Service not starting after new installed MM 5.31.4 LTS

Troubleshooting
1

Hello,

Summary
On my newly installed server the mattermost service does not start.
http access is currently sufficient. I will do certificates later.

Steps to reproduce

Expected behavior

  • Start of mattermost service :wink:
  • Mattermost in my browser instead of /var/www/index.html.

Observed behavior
…/opt# systemctl start mattermost.service
Job for mattermost.service failed because the control process exited with error code.
See “systemctl status mattermost.service” and “journalctl -xe” for details.

::/opt# cat /opt/mattermost/config/config.json | grep “SiteURL”
“SiteURL”: “http://gwmm1.vss.kapper.net”,

…/opt# curl localhost:8065
curl: (7) Failed to connect to localhost port 8065: Connection refused

Content of my /lib/systemd/system/mattermost.service:

[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

Content of my /etc/apache2/sites-available/mattermost.conf
> <VirtualHost :80>
> # If you’re not using a subdomain you may need to set a ServerAlias to:
> # ServerAlias www.mydomain.com
> ServerName gwmm1.vss.kapper.net
> ServerAdmin webmaster@localhost
> ProxyPreserveHost On
>
> # Set web sockets
> RewriteEngine On
> RewriteCond %{REQUEST_URI} /api/v[0-9]+/(users/)?websocket [NC,OR]
> RewriteCond %{HTTP:UPGRADE} ^WebSocket$ [NC,OR]
> RewriteCond %{HTTP:CONNECTION} ^Upgrade$ [NC]
> RewriteRule . ws://127.0.0.1:8065%{REQUEST_URI} [P,QSA,L]
>
>
> Require all granted
> ProxyPass http://127.0.0.1:8065/
> ProxyPassReverse http://127.0.0.1:8065/
> ProxyPassReverseCookieDomain 127.0.0.1 gwmm1.vss.kapper.net
>
>
>

Last 50 lines of journalctl -xe:

–
– The job identifier is 1837 and the job result is failed.
Apr 29 10:19:06 gwmm1 sshd[1316]: Connection closed by authenticating user root 119.2.51.138 port 62646 [preauth]
Apr 29 10:19:09 gwmm1 systemd[1]: mattermost.service: Scheduled restart job, restart counter is at 28.
– Subject: Automatic restarting of a unit has been scheduled
– Defined-By: systemd
– Support: Enterprise open source support | Ubuntu

– Automatic restarting of the unit mattermost.service has been scheduled, as the result for
– the configured Restart= setting for the unit.
Apr 29 10:19:09 gwmm1 systemd[1]: Stopped Mattermost.
– Subject: A stop job for unit mattermost.service has finished
– Defined-By: systemd
– Support: Enterprise open source support | Ubuntu

– A stop job for unit mattermost.service has finished.

– The job identifier is 1889 and the job result is done.
Apr 29 10:19:09 gwmm1 systemd[1]: Starting Mattermost…
– Subject: A start job for unit mattermost.service has begun execution
– Defined-By: systemd
– Support: Enterprise open source support | Ubuntu

– A start job for unit mattermost.service has begun execution.

– The job identifier is 1889.
Apr 29 10:19:09 gwmm1 mattermost[1318]: {“level”:“info”,“ts”:1619691549.439991,“caller”:“app/server.go:225”,“msg”:“Server is initializing…”}
Apr 29 10:19:09 gwmm1 mattermost[1318]: {“level”:“info”,“ts”:1619691549.4408529,“caller”:“app/web_hub.go:83”,“msg”:“Starting websocket hubs”,“number_of_hubs”:2}
Apr 29 10:19:09 gwmm1 mattermost[1318]: {“level”:“info”,“ts”:1619691549.442028,“caller”:“utils/i18n.go:90”,“msg”:“Loaded system translations”,“for locale”:“en”,“from locale”:“/opt/mattermost/i18n/en.json”}
Apr 29 10:19:09 gwmm1 mattermost[1318]: {“level”:“info”,“ts”:1619691549.453072,“caller”:“sqlstore/supplier.go:246”,“msg”:“Pinging SQL”,“database”:“master”}
Apr 29 10:19:09 gwmm1 mattermost[1318]: {“level”:“error”,“ts”:1619691549.4536614,“caller”:“sqlstore/supplier.go:258”,“msg”:“Failed to ping DB”,“error”:“dial tcp: lookup : no such host”,“retrying in seconds”:10}
Apr 29 10:19:16 gwmm1 sshd[1324]: Connection closed by authenticating user root 119.2.51.138 port 63814 [preauth]
Apr 29 10:19:19 gwmm1 mattermost[1318]: {“level”:“info”,“ts”:1619691559.453942,“caller”:“sqlstore/supplier.go:246”,“msg”:“Pinging SQL”,“database”:“master”}
Apr 29 10:19:19 gwmm1 mattermost[1318]: {“level”:“error”,“ts”:1619691559.4541655,“caller”:“sqlstore/supplier.go:258”,“msg”:“Failed to ping DB”,“error”:“dial tcp: lookup : no such host”,“retrying in seconds”:10}
Apr 29 10:19:26 gwmm1 sshd[1326]: Connection closed by authenticating user root 119.2.51.138 port 65150 [preauth]
Apr 29 10:19:29 gwmm1 mattermost[1318]: {“level”:“info”,“ts”:1619691569.4542823,“caller”:“sqlstore/supplier.go:246”,“msg”:“Pinging SQL”,“database”:“master”}
Apr 29 10:19:29 gwmm1 mattermost[1318]: {“level”:“error”,“ts”:1619691569.4544418,“caller”:“sqlstore/supplier.go:258”,“msg”:“Failed to ping DB”,“error”:“dial tcp: lookup : no such host”,“retrying in seconds”:10}
Apr 29 10:19:34 gwmm1 sshd[1328]: Connection closed by authenticating user root 119.2.51.138 port 49965 [preauth]
Apr 29 10:19:39 gwmm1 mattermost[1318]: {“level”:“info”,“ts”:1619691579.4544938,“caller”:“sqlstore/supplier.go:246”,“msg”:“Pinging SQL”,“database”:“master”}
Apr 29 10:19:39 gwmm1 mattermost[1318]: {“level”:“error”,“ts”:1619691579.4546628,“caller”:“sqlstore/supplier.go:258”,“msg”:“Failed to ping DB”,“error”:“dial tcp: lookup : no such host”,“retrying in seconds”:10}
Apr 29 10:19:42 gwmm1 sshd[1330]: Connection closed by authenticating user root 119.2.51.138 port 50966 [preauth]
Apr 29 10:19:49 gwmm1 mattermost[1318]: {“level”:“info”,“ts”:1619691589.4547691,“caller”:“sqlstore/supplier.go:246”,“msg”:“Pinging SQL”,“database”:“master”}
Apr 29 10:19:49 gwmm1 mattermost[1318]: {“level”:“error”,“ts”:1619691589.4549682,“caller”:“sqlstore/supplier.go:258”,“msg”:“Failed to ping DB”,“error”:“dial tcp: lookup : no such host”,“retrying in seconds”:10}
Apr 29 10:19:52 gwmm1 sshd[1332]: Connection closed by authenticating user root 119.2.51.138 port 52128 [preauth]
Apr 29 10:19:59 gwmm1 mattermost[1318]: {“level”:“info”,“ts”:1619691599.4550793,“caller”:“sqlstore/supplier.go:246”,“msg”:“Pinging SQL”,“database”:“master”}
Apr 29 10:19:59 gwmm1 mattermost[1318]: {“level”:“error”,“ts”:1619691599.455261,“caller”:“sqlstore/supplier.go:258”,“msg”:“Failed to ping DB”,“error”:“dial tcp: lookup : no such host”,“retrying in seconds”:10}
Apr 29 10:19:59 gwmm1 sshd[1334]: Connection closed by authenticating user root 119.2.51.138 port 53303 [preauth]
Apr 29 10:20:07 gwmm1 sshd[1340]: Connection closed by authenticating user root 119.2.51.138 port 54280 [preauth]
Apr 29 10:20:09 gwmm1 mattermost[1318]: {“level”:“info”,“ts”:1619691609.4553387,“caller”:“sqlstore/supplier.go:246”,“msg”:“Pinging SQL”,“database”:“master”}
Apr 29 10:20:09 gwmm1 mattermost[1318]: {“level”:“error”,“ts”:1619691609.4555233,“caller”:“sqlstore/supplier.go:258”,“msg”:“Failed to ping DB”,“error”:“dial tcp: lookup : no such host”,“retrying in seconds”:10}

Can anyone help me please? What going wrong here?

1 Like
2

This appears to be the issue. Your server is not starting because it cannot connect to the database. Can you confirm that your database is correctly set up with Mattermost?

3

Hello,

I’ve installed the db with this doc:
https://docs.mattermost.com/install/install-ubuntu-2004.html#installing-mysql-database-server

The database exists, but it does not contain any tables. Who creates the tables?

root@gwmm1:~# mysql -u root -p
Enter password:
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 28
Server version: 8.0.23-0ubuntu0.20.04.1 (Ubuntu)

Copyright (c) 2000, 2021, Oracle and/or its affiliates.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type ‘help;’ or ‘\h’ for help. Type ‘\c’ to clear the current input statement.

mysql> show databases;
±-------------------+
| Database |
±-------------------+
| information_schema |
| mattermost |
| mysql |
| performance_schema |
| sys |
±-------------------+
5 rows in set (0.13 sec)

mysql> use mattermost;
Database changed
mysql>
mysql> show tables;
Empty set (0.01 sec)

mysql>

Sorry, I’ve forgotten the keyword for the code view and it is not in the toolbar …

4

Hello, @SuziQ

Mattermost creates the database once you execute the Mattermost binary command in step 9b.

sudo -u mattermost ./bin/mattermost

May I know if you have ran this command before setting up the mattermost.service?

5

Hello, @ahmaddanial,
yes, I’m sure now that I’ve made this step, because it’s exactly in the order of the doc and I remember this output lines. But I’ve not paid attention that “Server is listening on :8065”.

My server is obviously not listening.

root@gwmm1:/opt/mattermost#     sudo -u mattermost ./bin/mattermost
{"level":"info","ts":1620046661.9210851,"caller":"app/server.go:225","msg":"Server is initializing..."}
{"level":"info","ts":1620046661.92131,"caller":"app/web_hub.go:83","msg":"Starting websocket hubs","number_of_hubs":2}
{"level":"info","ts":1620046661.9226801,"caller":"utils/i18n.go:90","msg":"Loaded system translations","for locale":"en","from locale":"/opt/mattermost/i18n/en.json"}
{"level":"info","ts":1620046661.9264934,"caller":"sqlstore/supplier.go:246","msg":"Pinging SQL","database":"master"}
{"level":"error","ts":1620046661.926854,"caller":"sqlstore/supplier.go:258","msg":"Failed to ping DB","error":"dial tcp: lookup <host-name-or-IP>: no such host","retrying in seconds":10}
{"level":"info","ts":1620046671.9269824,"caller":"sqlstore/supplier.go:246","msg":"Pinging SQL","database":"master"}
{"level":"error","ts":1620046671.9271867,"caller":"sqlstore/supplier.go:258","msg":"Failed to ping DB","error":"dial tcp: lookup <host-name-or-IP>: no such host","retrying in seconds":10}
{"level":"info","ts":1620046681.9272661,"caller":"sqlstore/supplier.go:246","msg":"Pinging SQL","database":"master"}
{"level":"error","ts":1620046681.9274542,"caller":"sqlstore/supplier.go:258","msg":"Failed to ping DB","error":"dial tcp: lookup <host-name-or-IP>: no such host","retrying in seconds":10}
{"level":"info","ts":1620046691.9275358,"caller":"sqlstore/supplier.go:246","msg":"Pinging SQL","database":"master"}
{"level":"error","ts":1620046691.9277158,"caller":"sqlstore/supplier.go:258","msg":"Failed to ping DB","error":"dial tcp: lookup <host-name-or-IP>: no such host","retrying in seconds":10}
{"level":"info","ts":1620046701.927819,"caller":"sqlstore/supplier.go:246","msg":"Pinging SQL","database":"master"}
{"level":"error","ts":1620046701.9279919,"caller":"sqlstore/supplier.go:258","msg":"Failed to ping DB","error":"dial tcp: lookup <host-name-or-IP>: no such host","retrying in seconds":10}
{"level":"info","ts":1620046706.1380496,"caller":"config/watcher.go:62","msg":"Config file watcher detected a change","path":"/opt/mattermost/config/config.json"}
{"level":"info","ts":1620046706.1402512,"caller":"config/watcher.go:62","msg":"Config file watcher detected a change","path":"/opt/mattermost/config/config.json"}
{"level":"info","ts":1620046711.9281106,"caller":"sqlstore/supplier.go:246","msg":"Pinging SQL","database":"master"}
{"level":"error","ts":1620046711.9282684,"caller":"sqlstore/supplier.go:258","msg":"Failed to ping DB","error":"dial tcp: lookup <host-name-or-IP>: no such host","retrying in seconds":10}

Should I start over again? From which step away?

6

Okay,

in config.php SqlSettings/DataSource was just your original line. A step that I seem to have overlooked (doc 7.). I’ve set mmuser’s password and IP instead default values and after sudo -u mattermost ./bin/mattermost now my server ist already listening on .8065 … :wink:

I was then able to create myself as a user via http://gwmm1.vss.kapper.net and also set up a team. System changes (e.g. language German) were not accepted.

After ^C, I see in the config.json file that someone has rewritten values, e.g. “DriverName”: “postgres” (instead of mysql) and also “DataSource”. So when I restart sudo -u mattermost ./bin/mattermost, I get the error “Failed to ping DB” again.

The service “mattermost.service” still does not start, aborts with:

Job for mattermost.service failed because the control process exited with error code.
See “systemctl status mattermost.service” and “journalctl -xe” for details.

BUT: Mattermost is running after all!

root@gwmm1:/opt/mattermost# ps -ef mattermost
matterm+ 21738 1 0 14:38 ? 00:00:00 /opt/mattermost/bin/mattermost
root 21801 19375 0 14:39 pts/2 00:00:00 grep --color=auto -i mattermost

All a bit confused for me. Anyway, I’m much further along now.
Only, who rewrites my config.json and why?

7

Bildschirmfoto vom 2021-05-03 17-25-26
Bildschirmfoto vom 2021-05-03 17-25-261177×674 76.3 KB

8

SEEMS TO BE SOLVED!

I don’t know why, but now mattermost.service runs, even after a server restart. After changing “DriverName” from postgres to mysql a few times, Mattermost now keeps this setting.

If this happens again, I will report back here.

Thank you very much for the above advice.

2 Likes