We're Hiring!

Mattermost, Inc.

Service not starting after new installed MM 5.31.4 LTS

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: http://www.ubuntu.com/support

– 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: http://www.ubuntu.com/support

– 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: http://www.ubuntu.com/support

– 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

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?

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 …

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?

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?

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?

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