MM randomly restart

Troubleshooting
1

Summary

My MM instance have some troubles last week.
At debug log I found information, that MM server restarts, but there is no command for restart

Logs

{“level”:“debug”,“ts”:1534321143.0788054,“caller”:“web/handlers.go:50”,“msg”:“POST - /api/v4/users/status/ids”}
{“level”:“debug”,“ts”:1534321143.259252,“caller”:“web/handlers.go:50”,“msg”:“POST - /api/v4/channels/members/me/view”}
{“level”:“debug”,“ts”:1534321143.5753138,“caller”:“web/handlers.go:50”,“msg”:“POST - /api/v4/users/status/ids”}
{“level”:“debug”,“ts”:1534321144.0559208,“caller”:“web/handlers.go:50”,“msg”:“POST - /api/v4/users/status/ids”}
{“level”:“debug”,“ts”:1534321144.4222775,“caller”:“wsapi/websocket_handler.go:26”,“msg”:“websocket: user_typing”}
{“level”:“debug”,“ts”:1534321144.8254626,“caller”:“web/handlers.go:50”,“msg”:“POST - /api/v4/users/status/ids”}
{“level”:“debug”,“ts”:1534321146.1583776,“caller”:“web/handlers.go:50”,“msg”:“POST - /api/v4/users/status/ids”}
{“level”:“debug”,“ts”:1534321146.8181524,“caller”:“web/handlers.go:50”,“msg”:“POST - /api/v4/users/status/ids”}
{“level”:“info”,“ts”:1534321149.2448986,“caller”:“jobs/schedulers.go:126”,“msg”:“Stopping schedulers.”}
{“level”:“debug”,“ts”:1534321149.2449918,“caller”:“jobs/schedulers.go:85”,“msg”:“Schedulers received stop signal.”}
{“level”:“info”,“ts”:1534321149.2450175,“caller”:“jobs/schedulers.go:69”,“msg”:“Schedulers stopped.”}
{“level”:“debug”,“ts”:1534321149.2450523,“caller”:“jobs/jobs_watcher.go:63”,“msg”:“Watcher Stopping”}
{“level”:“debug”,“ts”:1534321149.245076,“caller”:“jobs/jobs_watcher.go:54”,“msg”:“Watcher: Received stop signal”}
{“level”:“debug”,“ts”:1534321149.2451417,“caller”:“jobs/jobs_watcher.go:47”,“msg”:“Watcher Finished”}
{“level”:“debug”,“ts”:1534321149.2451632,“caller”:“migrations/worker.go:64”,“msg”:“Worker stopping”,“worker”:“Migrations”}
{“level”:“debug”,“ts”:1534321149.245186,“caller”:“migrations/worker.go:54”,“msg”:“Worker received stop signal”,“worker”:“Migrations”}
{“level”:“debug”,“ts”:1534321149.245208,“caller”:“migrations/worker.go:47”,“msg”:“Worker finished”,“worker”:“Migrations”}
{“level”:“info”,“ts”:1534321149.2452328,“caller”:“jobs/workers.go:170”,“msg”:“Stopped workers”}
{“level”:“info”,“ts”:1534321149.245263,“caller”:“app/app.go:257”,“msg”:“Stopping Server…”}
{“level”:“info”,“ts”:1534321149.24538,“caller”:“app/web_hub.go:120”,“msg”:“stopping websocket hub connections”}

2

Hi @alexmorbo, thank you for reaching out!

  1. What Mattermost server version are you using?
  2. What OS and version are you using?
  3. Do you any automation setup such as puppet or chef? Maybe a cron job is shutting down Mattermost?
3

Hi @amy.blais

  1. Last one 5.1.0
  2. Ubuntu 16.04.4 LTS
  3. no automation

I checked crontab from root and mattermost user, everything clear

4

@alexmorbo Thank you, I’ll ask our devs about this now.

5

Hi @alexmorbo,

Feedback from one of our community members!

Are you using the systemd services files from the docs? If yes, you should check your database server’s logs as well (the Mattermost service and the database service defined there depend on each other - e.g. if one restarts so does the other).

Also, did you do any updates to Mattermost recently? If not, then something else may have changed. E.g. there was a postgresql security update in the last 2-20 days.

6

Hi @amy.blais
I check my mysql server logs.
There is no restarts at 15 days

7

Hi @alexmorbo,

Is there a reason you decided to post that part of your log? If not, can you help post a log containing all messages between two forced restarts?

8

Hello, I had same issue like this.
MM has randomly restarts 10 times per a day.

{"level":"info","ts":1620275674.1296022,"caller":"app/server.go:329","msg":"Stopping Server..."}
{"level":"info","ts":1620275674.1296859,"caller":"app/web_hub.go:120","msg":"stopping websocket hub connections"}
{"level":"info","ts":1620275674.4750407,"caller":"app/plugin.go:267","msg":"Shutting down plugins"}
{"level":"warn","ts":1620275675.48142,"caller":"app/server.go:313","msg":"context deadline exceeded"}
{"level":"info","ts":1620275675.5172005,"caller":"jobs/workers.go:184","msg":"Stopped workers"}
{"level":"info","ts":1620275675.5172365,"caller":"jobs/schedulers.go:139","msg":"Stopping schedulers."}
{"level":"info","ts":1620275675.5172665,"caller":"jobs/schedulers.go:75","msg":"Schedulers stopped."}
{"level":"info","ts":1620275675.5172834,"caller":"sqlstore/supplier.go:917","msg":"Closing SqlStore"}
{"level":"info","ts":1620275675.5175946,"caller":"app/server.go:367","msg":"Server stopped"}
{"level":"info","ts":1620275695.8416317,"caller":"utils/i18n.go:83","msg":"Loaded system translations","for locale":"ko","from locale":"/opt/mattermost/i18n/ko.json"}
{"level":"info","ts":1620275695.841779,"caller":"app/server_app_adapters.go:59","msg":"Server is initializing..."}
{"level":"info","ts":1620275695.8441267,"caller":"sqlstore/supplier.go:222","msg":"Pinging SQL","database":"master"}
{"level":"error","ts":1620275697.8645284,"caller":"app/server_app_adapters.go:126","msg":"SiteURL must be set. Some features will operate incorrectly if the SiteURL is not set. See documentation for details: http://about.mattermost.com/default-site-url"}
{"level":"info","ts":1620275697.871552,"caller":"mlog/log.go:166","msg":"Starting up plugins"}
{"level":"info","ts":1620275697.871837,"caller":"app/plugin.go:197","msg":"Syncing plugins from the file store"}
{"level":"info","ts":1620275698.1520033,"caller":"app/plugin.go:250","msg":"Syncing plugin from file store","bundle":"plugins/com.github.matterpoll.matterpoll.tar.gz"}
{"level":"info","ts":1620275699.0774984,"caller":"app/plugin.go:250","msg":"Syncing plugin from file store","bundle":"plugins/com.github.scottleedavis.mattermost-plugin-remind.tar.gz"}
{"level":"info","ts":1620275699.7852337,"caller":"app/plugin.go:250","msg":"Syncing plugin from file store","bundle":"plugins/standup-raven.tar.gz"}
{"level":"info","ts":1620275702.285145,"caller":"mlog/sugar.go:19","msg":"Ensuring Surveybot exists","plugin_id":"com.mattermost.nps"}
{"level":"info","ts":1620275702.8408804,"caller":"app/server.go:216","msg":"Current version is 5.16.0 (dev/Thu, Oct 31, 2019  3:15:33 AM/0061eefb02a7ac4b579c07b0766c8fd82efc9158/none)"}
{"level":"info","ts":1620275702.841098,"caller":"app/server.go:217","msg":"Enterprise Enabled: false"}
{"level":"info","ts":1620275702.8415031,"caller":"app/server.go:219","msg":"Current working directory is /opt/mattermost"}
{"level":"info","ts":1620275702.8417888,"caller":"app/server.go:220","msg":"Loaded config","source":"file:///opt/mattermost/config/config.json"}
{"level":"info","ts":1620275702.8636155,"caller":"sqlstore/post_store.go:1387","msg":"Post.Message has size restrictions","max_characters":16383,"max_bytes":65535}
{"level":"info","ts":1620275702.9603548,"caller":"jobs/workers.go:68","msg":"Starting workers"}
{"level":"info","ts":1620275702.9604585,"caller":"app/server.go:423","msg":"Starting Server..."}
{"level":"info","ts":1620275702.9607027,"caller":"app/server.go:489","msg":"Server is listening on [::]:80"}
{"level":"info","ts":1620275702.963973,"caller":"jobs/schedulers.go:72","msg":"Starting schedulers."}
{"level":"info","ts":1620275702.9737315,"caller":"app/web_hub.go:75","msg":"Starting 4 websocket hubs"}
{"level":"info","ts":1620275702.9754996,"caller":"commands/server.go:105","msg":"Sending systemd READY notification."}

Any helps appreciated. Thanks

9

Hello, @LumpKim

Firstly, you are running on a very old version of Mattermost:

{"level":"info","ts":1620275702.8408804,"caller":"app/server.go:216","msg":"Current version is 5.16.0 (dev/Thu, Oct 31, 2019  3:15:33 AM/0061eefb02a7ac4b579c07b0766c8fd82efc9158/none)"}

I would definitely recommend you to upgrade your Mattermost instance first before we proceed.

Next, do you happen to set up Mattermost using mattermost.service and if yes, would you mind sharing the content here? By default, it will look like this:

[Unit]
Description=Mattermost
After=network.target
After=mysql.service
BindsTo=mysql.service

[Service]
Type=notify
ExecStart=/opt/mattermost/bin/mattermost
TimeoutStartSec=3600
Restart=always
RestartSec=10
WorkingDirectory=/opt/mattermost
User=mattermost
Group=mattermost
LimitNOFILE=49152

[Install]
WantedBy=mysql.service

Just trying to confirm if there are any condition that causes the server to stop and restart automatically.

1 Like