[SOLVED] Mattermost server not starting after upgrade (4.5.0 to 4.6.1)

Ju_St · February 2, 2018, 8:32am

Summary

Following the steps to upgrade the mattermost server version results in mattermost failing to restart (nginx 502 bad gateway)

Steps followed

Were using Debian 9. DB Postgres 9.5. Followed steps from guide to upgrade 4.5.0 enterprise to 4.6.1 enterprise

downloaded and extracted server files, shut down mattermost
backup of old folder to mattermost-back-date
copy over new mattermost server folder to /opt/
restore config, data and logs folders from backup
change ownership of new files
restart mattermost server
activate cap_net_bind_service

Result

However the mattermost server doesn’t restart. systemctl status mattermost shows:

mattermost.service - Mattermost
Loaded: loaded (/lib/systemd/system/mattermost.service; enabled; vendor preset: enabled)
Active: activating (auto-restart) (Result: exit-code) since Fri 2018-02-02 15:15:59 +07; 4s ago
Process: 5241 ExecStart=/opt/mattermost/bin/platform (code=exited, status=2)
Main PID: 5241 (code=exited, status=2)

Feb 02 15:15:59 servername systemd[1]: mattermost.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Feb 02 15:15:59 servername systemd[1]: mattermost.service: Unit entered failed state.
Feb 02 15:15:59 servername systemd[1]: mattermost.service: Failed with result ‘exit-code’.

Twilek · February 4, 2018, 10:17am

Take the command line from the /lib/systemd/system/mattermost.service and try to start mattermost manually with that. Maybe that will yield a more meaningful error message.

Ju_St · February 5, 2018, 2:33am

Hello Twilek,
starting the server with ./platform server did the trick! We’re on version 4.6.1 now
Thanks for your help!

edit: Alright, seems like we’re not there yet…

Starting the server from the ./platform server command works, but I can’t get it to start with systemctl start mattermost. It’ll show the same error. Starting the serer with the platform command shows the following:

[2018/02/05 10:04:38 +07] [INFO] Loaded system translations for ‘en’ from ‘/opt/mattermost/i18n/en.json’
[2018/02/05 10:04:39 +07] [INFO] Current version is 4.6.0 (4.6.1/Tue Jan 30 22:08:22 UTC 2018/cc82749d4f8c47bce201123aedcd8c564ceffcb8/721817a2503c55d24da15aebb0181ec794012058)
[2018/02/05 10:04:39 +07] [INFO] Enterprise Enabled: true
[2018/02/05 10:04:39 +07] [INFO] Current working directory is /opt/mattermost/bin
[2018/02/05 10:04:39 +07] [INFO] Loaded config file from /opt/mattermost/config/config.json
[2018/02/05 10:04:40 +07] [INFO] Loaded system translations for ‘en’ from ‘/opt/mattermost/i18n/en.json’
[2018/02/05 10:04:40 +07] [INFO] Server is initializing…
[2018/02/05 10:04:40 +07] [INFO] Pinging SQL master database
[2018/02/05 10:04:40 +07] [INFO] Able to write files to local storage.
[2018/02/05 10:04:40 +07] [INFO] License key from https://mattermost.com required to unlock enterprise features.
[2018/02/05 10:04:40 +07] [INFO] Starting up plugins
[2018/02/05 10:04:40 +07] [EROR] failed to start up plugins: mkdir ./client/plugins: no such file or directory
[2018/02/05 10:04:40 +07] [INFO] Starting Server…
[2018/02/05 10:04:40 +07] [INFO] Server is listening on [::]:8065
[2018/02/05 10:04:40 +07] [INFO] API version 3 is scheduled for deprecation. Please see https://api.mattermost.com for details.
[2018/02/05 10:04:40 +07] [INFO] Starting 2 websocket hubs
[2018/02/05 10:04:40 +07] [INFO] Starting up plugins
[2018/02/05 10:04:40 +07] [EROR] failed to start up plugins: mkdir ./client/plugins: no such file or directory
[2018/02/05 10:04:40 +07] [INFO] Starting up plugins
[2018/02/05 10:04:40 +07] [EROR] failed to start up plugins: mkdir ./client/plugins: no such file or directory
[2018/02/05 10:04:40 +07] [INFO] Starting workers
[2018/02/05 10:04:40 +07] [INFO] Starting schedulers.
[2018/02/05 10:04:48 +07] [EROR] /api/v4/plugins/webapp:GetActivePluginManifests code=501 rid=ynwo1gtcfjn6jrsi49mjdpupno uid=zx55qysi13gy3bxmjz1y17h5ny ip=203.172.103.162 Plugins have been disabled. [details: ]
[2018/02/05 10:04:54 +07] [EROR] /api/v4/plugins/webapp:GetActivePluginManifests code=501 rid=8fyb79y4u38sxjbd71tjt4kmue uid=stee8rmw67ntzcjf9mueqoktmc ip=58.11.156.114 Plugins have been disabled. [details: ]
[2018/02/05 10:05:36 +07] [EROR] /api/v4/plugins/webapp:GetActivePluginManifests code=501 rid=f9k9q8xni7d93nw3d7ax5nerch uid=zywk4d55wtgzmkmjrm4ny1mcao ip=203.172.103.162 Plugins have been disabled. [details: ]
[2018/02/05 10:05:36 +07] [EROR] /api/v4/plugins/webapp:GetActivePluginManifests code=501 rid=k8ccd379rib4mmmws4t135tdth uid=stee8rmw67ntzcjf9mueqoktmc ip=58.11.156.114 Plugins have been disabled. [details: ]
[2018/02/05 10:05:36 +07] [EROR] /api/v4/plugins/webapp:GetActivePluginManifests code=501 rid=fe3f3cfu1pd1jcsaxdy5cd4e7y uid=tdrjduqoi7f9jdts7qd9989dwh ip=203.172.103.162 Plugins have been disabled. [details: ]
[2018/02/05 10:05:43 +07] [EROR] /api/v4/plugins/webapp:GetActivePluginManifests code=501 rid=uqhh6cjg1if1zmx9uw8xj3gmph uid=c3xsn3bozff7mxoigbiwspufpo ip=203.172.103.162 Plugins have been disabled. [details: ]
[2018/02/05 10:05:43 +07] [EROR] /api/v4/plugins/webapp:GetActivePluginManifests code=501 rid=hfz7xnkjetdzdgdk6wk1dgkpje uid=u5t3y3mx33bftkjxy8ty8yefwh ip=203.172.103.162 Plugins have been disabled. [details: ]
[2018/02/05 10:05:43 +07] [EROR] /api/v4/plugins/webapp:GetActivePluginManifests code=501 rid=abr71rjj83d8xdwhbjo8yjyw6r uid=tsci4cy4d7bzpb944i91odyrdy ip=27.254.21.179 Plugins have been disabled. [details: ]
[2018/02/05 10:05:44 +07] [EROR] /api/v4/plugins/webapp:GetActivePluginManifests code=501 rid=5s1mmrdxqigy8ddhapzsc9aakc uid=479g7aob3j8jdmtusnychc5s6a ip=203.172.103.162 Plugins have been disabled. [details: ]
[2018/02/05 10:05:45 +07] [EROR] /api/v4/plugins/webapp:GetActivePluginManifests code=501 rid=bmms8rdz6byk3k1zdt7w94ukth uid=zx55qysi13gy3bxmjz1y17h5ny ip=203.172.103.162 Plugins have been disabled. [details: ]

Another weird thing is that it seems the files are not linked any longer, even though I’ve copied data over. When moving into a chat that has shared files it’ll show for example:

[2018/02/05 10:07:44 +07] [EROR] /api/v4/files/fzx8s65n6tbexdbkqpog4xrexw:ReadFile code=404 rid=6bk948axjfg19xn6digfombrdr uid=stee8rmw67ntzcjf9mueqoktmc ip=58.11.156.114 Encountered an error reading from local server storage [details: open data/20180130/teams/noteam/channels/mrnsc3ikd3bpfqacain6iwqate/users/stee8rmw67ntzcjf9mueqoktmc/fzx8s65n6tbexdbkqpog4xrexw/Example 4.PNG: no such file or directory]

Trying to downgrade doesn’t work either

When trying to go back to 4.5 we run into another issue now (this worked before starting the server manually). Replacing mattermost 4.6 with the backup 4.5 and starting the 4.5 server will show this:

[2018/02/05 10:00:28 +07] [INFO] Loaded system translations for ‘en’ from ‘/opt/mattermost/i18n/en.json’
[2018/02/05 10:00:30 +07] [INFO] Current version is 4.5.0 (4.5.0/Fri Dec 15 23:15:33 UTC 2017/03f5c939deb4a6ab2fd01639b5570799e4118bab/dc1a5c62b18d87b9effd4ec249f29c77d1ffdde0)
[2018/02/05 10:00:30 +07] [INFO] Enterprise Enabled: true
[2018/02/05 10:00:30 +07] [INFO] Current working directory is /opt/mattermost/bin
[2018/02/05 10:00:30 +07] [INFO] Loaded config file from /opt/mattermost/config/config.json
[2018/02/05 10:00:30 +07] [INFO] Loaded system translations for ‘en’ from ‘/opt/mattermost/i18n/en.json’
[2018/02/05 10:00:30 +07] [INFO] Server is initializing…
[2018/02/05 10:00:30 +07] [INFO] Pinging SQL master database
[2018/02/05 10:00:30 +07] [CRIT] Database schema version 4.6.0 is no longer supported. This Mattermost server supports automatic upgrades from schema version 3.0.0 through schema version 4.5.0. Downgrades are not supported. Please manually upgrade to at least version 3.0.0 before continuing

Twilek · February 5, 2018, 8:52am

Do you have a seperate Database backup from 4.5.? Otherwise a downgrade will be problematic.
Have you changed the data directory because mattermost seems to fail to find a file.
I am also not sure if the server is listening correctly. You might want to check the IP in your config at “ListenAddress”:
Hope that helps…

Ju_St · February 5, 2018, 12:24pm

Thanks Twilek, for the time being, everything is running normal again (on server 4.5) - we restored to a backup from last night before the changes.

I’ll check the data directory and listenaddress and report back.

Ju_St · February 7, 2018, 8:50am

Hello Twilek,

I checked the listenaddress in the system console (it was :8065) and changed it to (our ip:8065). The storage location is set to the default ./data/ which is also where our files are saved when looking through the folders.

Not a lot of new revelations I’m afraid…any suggestions on how to proceed?

ElNovi · February 7, 2018, 9:30am

Try to look at this 502 Bad Gateway after upgrading to GitLab 10.3.3

Ju_St · February 8, 2018, 6:05am

Hello ElNovi,

thanks for your suggestion. “Forward 80 to 443” is already set to false in the mattermost config. We’ve set up all https related settings in our nginx config.

ccbrown · February 9, 2018, 3:36pm

@Ju_St

If the server command works, but the systemctl service doesn’t, my best guess is that you’re hitting a permissions issue.

In your service file, you should have a line with something like User=mattermost. Try running the command manually, but make sure you run it as the user in your service file. For example, if the user is “mattermost”:

cd /opt/mattermost
sudo -u mattermost ./bin/platform

Hopefully that will fail in the same way that running via systemctl fails, but give us some more useful log output. And if that is the case, you probably need to double check that the user has appropriate permissions in /opt/mattermost:

sudo chown -R mattermost:mattermost /opt/mattermost

Ju_St · February 13, 2018, 2:18am

@ccbrown thanks, that did the trick! It seems I messed up setting the right permissions during the upgrade. I though I had changed the username and instead of checking just went for it. Feeling a bit stupid right now

In any case, thanks a lot for your help and patience! We’re on 4.6.1 now and everything is running smoothly.