MM setup issue on naked Ubuntu 24.04 LTS with postgres

Summary
Can’t start MM initially after postgres setup

Steps to reproduce

  • Fresh Hetzner vCPU server with Ubuntu 24.04 LTS (I’m using a 2 vCPU instance with 4GB)
  • sudo apt update && sudo apt upgrade -y
  • Installed postgress (postgresql-all), added database, user, granted right:
root@ubuntu-4gb-nbg1-1:~# sudo -u postgres psql
Password for user postgres:
psql (16.4 (Ubuntu 16.4-0ubuntu0.24.04.1))
Type "help" for help.
postgres=# CREATE DATABASE mattermost;
postgres=# CREATE USER mmuser WITH PASSWORD 'XXXXXX';
postgres=# GRANT ALL PRIVILEGES ON DATABASE mattermost to mmuser;
postgres=# GRANT USAGE, CREATE ON SCHEMA PUBLIC TO mmuser;
postgres=# \q
root@ubuntu-4gb-nbg1-1:~# nano /etc/postgresql/16/main/pg_hba.conf
root@ubuntu-4gb-nbg1-1:~# sudo systemctl restart postgresql
root@ubuntu-4gb-nbg1-1:~# psql --dbname=mattermost --username=mmuser --password
Password:
psql (16.4 (Ubuntu 16.4-0ubuntu0.24.04.1))
Type "help" for help.

mattermost=> \q

My pg_hba.conf

local   all             postgres                                md5

# TYPE  DATABASE        USER            ADDRESS                 METHOD

# "local" is for Unix domain socket connections only
local   all             all                                     trust
# IPv4 local connections:
host    all             all             127.0.0.1/32            trust
# IPv6 local connections:
host    all             all             ::1/128                 trust
# Allow replication connections from localhost, by a user with the
# replication privilege.
local   replication     all                                     peer
host    replication     all             127.0.0.1/32            scram-sha-256
host    replication     all             ::1/128                 scram-sha-256

My config:

"DriverName": "postgres",
"DataSource": "postgres://mmuser:XXXXXX@localhost/mattermost?sslmode=disable\u0026connect_timeout=10\u0026binary_parameters=yes",

Expected behavior

  • Mattermost server should start and end in status Active: inactive (dead).

Observed behavior
Process hangs after: root@ubuntu-4gb-nbg1-1:~# sudo systemctl start mattermost.service:

Aug 23 01:00:45 ubuntu-4gb-nbg1-1 systemd[1]: Starting mattermost.service - Mattermost...
Aug 23 01:00:46 ubuntu-4gb-nbg1-1 mattermost[12258]: {"timestamp":"2024-08-23 01:00:46.384 Z","level":"debug","msg":"Advanced logging config not provided for logging","caller":"platform/config.go:165"}
Aug 23 01:00:46 ubuntu-4gb-nbg1-1 mattermost[12258]: {"timestamp":"2024-08-23 01:00:46.384 Z","level":"debug","msg":"Advanced logging config not provided for notification logging","caller":"platform/config.go:165"}
Aug 23 01:00:46 ubuntu-4gb-nbg1-1 mattermost[12258]: {"timestamp":"2024-08-23 01:00:46.384 Z","level":"info","msg":"Server is initializing...","caller":"platform/service.go:175","go_version":"go1.21.8"}
Aug 23 01:00:46 ubuntu-4gb-nbg1-1 mattermost[12258]: {"timestamp":"2024-08-23 01:00:46.385 Z","level":"info","msg":"Pinging SQL","caller":"sql/sql_utils.go:67","database":"master","dataSource":"postgres://%2A%2A%2A%2A:%2A%2A%2A%2A@localhost/mattermost?binary_parameters=yes

Could you please send a kill -SIGQUIT <PID> to the mattermost process, and capture the output from journalctl -r -u mattermost? Thanks.

Hope this is the right thing - It initially gave me the logs in desc order and I had to play around a bit. I’m not seeing any helpful additional information:

SIGQUIT: quit
PC=0x476141 m=3 sigcode=0
goroutine 0 [idle]:
runtime.futex()
	runtime/sys_linux_amd64.s:557 +0x21 fp=0x7351919ffbf0 sp=0x7351919ffbe8 pc=0x476141
runtime.futexsleep(0x0?, 0x0?, 0x7351919ffc98?)
	runtime/os_linux.go:69 +0x30 fp=0x7351919ffc40 sp=0x7351919ffbf0 pc=0x43a0b0
runtime.notesleep(0xc000076948)
	runtime/lock_futex.go:160 +0x87 fp=0x7351919ffc78 sp=0x7351919ffc40 pc=0x410be7
runtime.mPark(...)
	runtime/proc.go:1634
runtime.stopm()
	runtime/proc.go:2531 +0x8c fp=0x7351919ffca8 sp=0x7351919ffc78 pc=0x4447cc
runtime.findRunnable()
	runtime/proc.go:3224 +0xb9c fp=0x7351919ffdb8 sp=0x7351919ffca8 pc=0x4460fc
runtime.schedule()
	runtime/proc.go:3577 +0xb1 fp=0x7351919ffdf0 sp=0x7351919ffdb8 pc=0x446ef1
runtime.park_m(0xc0000071e0?)
	runtime/proc.go:3740 +0x11f fp=0x7351919ffe38 sp=0x7351919ffdf0 pc=0x4473ff
runtime.mcall()
	runtime/asm_amd64.s:458 +0x4e fp=0x7351919ffe50 sp=0x7351919ffe38 pc=0x47230e
rax    0xca
rbx    0x0
rcx    0x476143
rdx    0x0
rdi    0xc000076948
rsi    0x80
rbp    0x7351919ffc30
rsp    0x7351919ffbe8
r8     0x0
r9     0x0
r10    0x0
r11    0x286
r12    0x7351919ffc40
r13    0xc0027db734
r14    0xc000006ea0
r15    0x0
rip    0x476141
rflags 0x286
cs     0x33
fs     0x0
gs     0x0
-----
SIGQUIT: quit
PC=0x407fce m=4 sigcode=0
goroutine 0 [idle]:
runtime/internal/syscall.Syscall6()
	runtime/internal/syscall/asm_linux_amd64.s:36 +0xe fp=0x735190fff5c8 sp=0x735190fff5c0 pc=0x407fce
runtime/internal/syscall.EpollWait(0x5?, {0x735190fff690?, 0x735100000010?, 0x735100000001?}, 0x1?, 0x0?)
	runtime/internal/syscall/syscall_linux.go:55 +0x45 fp=0x735190fff618 sp=0x735190fff5c8 pc=0x407f45
runtime.netpoll(0xc000052020?)
	runtime/netpoll_epoll.go:118 +0xcb fp=0x735190fffca8 sp=0x735190fff618 pc=0x439deb
runtime.findRunnable()
	runtime/proc.go:3186 +0x825 fp=0x735190fffdb8 sp=0x735190fffca8 pc=0x445d85
runtime.schedule()
	runtime/proc.go:3577 +0xb1 fp=0x735190fffdf0 sp=0x735190fffdb8 pc=0x446ef1
runtime.park_m(0xc0025be340?)
	runtime/proc.go:3740 +0x11f fp=0x735190fffe38 sp=0x735190fffdf0 pc=0x4473ff
runtime.mcall()
	runtime/asm_amd64.s:458 +0x4e fp=0x735190fffe50 sp=0x735190fffe38 pc=0x47230e
rax    0xfffffffffffffffc
rbx    0x4
rcx    0x407fce
rdx    0x80
rdi    0x4
rsi    0x735190fff690
rbp    0x735190fff608
rsp    0x735190fff5c0
r8     0x0
r9     0x0
r10    0x1383
r11    0x246
r12    0x735190fff698
r13    0xc0027db734
r14    0xc000007520
r15    0x0
rip    0x407fce
rflags 0x246
cs     0x33
fs     0x0
gs     0x0
-----
SIGQUIT: quit
PC=0x476141 m=5 sigcode=0
goroutine 0 [idle]:
runtime.futex()
	runtime/sys_linux_amd64.s:557 +0x21 fp=0x73518bdffd70 sp=0x73518bdffd68 pc=0x476141
runtime.futexsleep(0x73518bdffdd8?, 0x0?, 0x8?)
	runtime/os_linux.go:69 +0x30 fp=0x73518bdffdc0 sp=0x73518bdffd70 pc=0x43a0b0
runtime.notesleep(0x67ce1f8)
	runtime/lock_futex.go:160 +0x87 fp=0x73518bdffdf8 sp=0x73518bdffdc0 pc=0x410be7
runtime.templateThread()
	runtime/proc.go:2509 +0x71 fp=0x73518bdffe18 sp=0x73518bdffdf8 pc=0x4446b1
runtime.mstart1()
	runtime/proc.go:1602 +0x93 fp=0x73518bdffe40 sp=0x73518bdffe18 pc=0x443213
runtime.mstart0()
	runtime/proc.go:1559 +0x76 fp=0x73518bdffe70 sp=0x73518bdffe40 pc=0x443156
runtime.mstart()
	runtime/asm_amd64.s:394 +0x5 fp=0x73518bdffe78 sp=0x73518bdffe70 pc=0x472285
rax    0xca
rbx    0x0
rcx    0x476143
rdx    0x0
rdi    0x67ce1f8
rsi    0x80
rbp    0x73518bdffdb0
rsp    0x73518bdffd68
r8     0x0
r9     0x0
r10    0x0
r11    0x286
r12    0xc0001061a0
r13    0xffffffffffffff80
r14    0xc0001061a0
r15    0x7ffe0a264480
rip    0x476141
rflags 0x286
cs     0x33
fs     0x0
gs     0x0
-----
SIGQUIT: quit
PC=0x476141 m=6 sigcode=0
goroutine 0 [idle]:
runtime.futex()
	runtime/sys_linux_amd64.s:557 +0x21 fp=0x73518b3ffbf0 sp=0x73518b3ffbe8 pc=0x476141
runtime.futexsleep(0x73518b3ffc70?, 0x8b3ffc70?, 0x44cc47?)
	runtime/os_linux.go:69 +0x30 fp=0x73518b3ffc40 sp=0x73518b3ffbf0 pc=0x43a0b0
runtime.notesleep(0xc0002f6548)
	runtime/lock_futex.go:160 +0x87 fp=0x73518b3ffc78 sp=0x73518b3ffc40 pc=0x410be7
runtime.mPark(...)
	runtime/proc.go:1634
runtime.stopm()
	runtime/proc.go:2531 +0x8c fp=0x73518b3ffca8 sp=0x73518b3ffc78 pc=0x4447cc
runtime.findRunnable()
	runtime/proc.go:3224 +0xb9c fp=0x73518b3ffdb8 sp=0x73518b3ffca8 pc=0x4460fc
runtime.schedule()
	runtime/proc.go:3577 +0xb1 fp=0x73518b3ffdf0 sp=0x73518b3ffdb8 pc=0x446ef1
runtime.park_m(0xc000007040?)
	runtime/proc.go:3740 +0x11f fp=0x73518b3ffe38 sp=0x73518b3ffdf0 pc=0x4473ff
runtime.mcall()
	runtime/asm_amd64.s:458 +0x4e fp=0x73518b3ffe50 sp=0x73518b3ffe38 pc=0x47230e
rax    0xca
rbx    0x0
rcx    0x476143
rdx    0x0
rdi    0xc0002f6548
rsi    0x80
rbp    0x73518b3ffc30
rsp    0x73518b3ffbe8
r8     0x0
r9     0x0
r10    0x0
r11    0x286
r12    0x5
r13    0x65503a0
r14    0xc000107ba0
r15    0x3
rip    0x476141
rflags 0x286
cs     0x33
fs     0x0
gs     0x0
mattermost.service: Main process exited, code=dumped, status=6/ABRT
mattermost.service: Failed with result 'core-dump'.
Failed to start mattermost.service - Mattermost.
mattermost.service: Consumed 2.809s CPU time.
mattermost.service: Scheduled restart job, restart counter is at 7.
Starting mattermost.service - Mattermost...
{"timestamp":"2024-08-23 08:15:29.044 Z","level":"debug","msg":"Advanced logging config not provided for logging","caller":"platform/config.go:165"}
{"timestamp":"2024-08-23 08:15:29.044 Z","level":"debug","msg":"Advanced logging config not provided for notification logging","caller":"platform/config.go:165"}
{"timestamp":"2024-08-23 08:15:29.044 Z","level":"info","msg":"Server is initializing...","caller":"platform/service.go:175","go_version":"go1.21.8"}
{"timestamp":"2024-08-23 08:15:29.046 Z","level":"info","msg":"Pinging SQL","caller":"sql/sql_utils.go:67","database":"master","dataSource":"postgres://%2A%2A%2A%2A:%2A%2A%2A%2A@localhost/mattermost?binary_parameters=yes&connect_timeout=10&sslmode=disable"}
root@ubuntu-4gb-nbg1-1:~# 

If I purely run the command you posted the first few lines are:

root@ubuntu-4gb-nbg1-1:~# journalctl -r -u mattermost
Aug 23 08:15:29 ubuntu-4gb-nbg1-1 mattermost[165697]: {"timestamp":"2024-08-23 >
Aug 23 08:15:29 ubuntu-4gb-nbg1-1 mattermost[165697]: {"timestamp":"2024-08-23 >
Aug 23 08:15:29 ubuntu-4gb-nbg1-1 mattermost[165697]: {"timestamp":"2024-08-23 >
Aug 23 08:15:29 ubuntu-4gb-nbg1-1 mattermost[165697]: {"timestamp":"2024-08-23 >
Aug 23 08:15:28 ubuntu-4gb-nbg1-1 systemd[1]: Starting mattermost.service - Mat>
Aug 23 08:15:28 ubuntu-4gb-nbg1-1 systemd[1]: mattermost.service: Scheduled res>
Aug 23 08:15:18 ubuntu-4gb-nbg1-1 systemd[1]: mattermost.service: Consumed 2.80>
Aug 23 08:15:18 ubuntu-4gb-nbg1-1 systemd[1]: Failed to start mattermost.servic>
Aug 23 08:15:18 ubuntu-4gb-nbg1-1 systemd[1]: mattermost.service: Failed with r>
Aug 23 08:15:18 ubuntu-4gb-nbg1-1 systemd[1]: mattermost.service: Main process >
Aug 23 08:15:11 ubuntu-4gb-nbg1-1 mattermost[143922]: gs     0x0
Aug 23 08:15:11 ubuntu-4gb-nbg1-1 mattermost[143922]: fs     0x0
Aug 23 08:15:11 ubuntu-4gb-nbg1-1 mattermost[143922]: cs     0x33
Aug 23 08:15:11 ubuntu-4gb-nbg1-1 mattermost[143922]: rflags 0x286
Aug 23 08:15:11 ubuntu-4gb-nbg1-1 mattermost[143922]: rip    0x476141
Aug 23 08:15:11 ubuntu-4gb-nbg1-1 mattermost[143922]: r15    0x3
Aug 23 08:15:11 ubuntu-4gb-nbg1-1 mattermost[143922]: r14    0xc000107ba0
Aug 23 08:15:11 ubuntu-4gb-nbg1-1 mattermost[143922]: r13    0x65503a0
Aug 23 08:15:11 ubuntu-4gb-nbg1-1 mattermost[143922]: r12    0x5
Aug 23 08:15:11 ubuntu-4gb-nbg1-1 mattermost[143922]: r11    0x286
Aug 23 08:15:11 ubuntu-4gb-nbg1-1 mattermost[143922]: r10    0x0
Aug 23 08:15:11 ubuntu-4gb-nbg1-1 mattermost[143922]: r9     0x0
Aug 23 08:15:11 ubuntu-4gb-nbg1-1 mattermost[143922]: r8     0x0
lines 1-23

Ah you are right about the -r flag. In any case, it doesn’t look like it’s actually doing anything, just sleeping.

Could you start the service again, and then run netstat -antp to check if connection to the DB is being made properly? Actually, even if it didn’t, it should show in the SIGQUIT output. So it’s a bit strange as to why it isn’t doing that.

When I run root@ubuntu-4gb-nbg1-1:~# sudo systemctl start mattermost it just hangs. If I open another terminal and do netstat -antp I get:

root@ubuntu-4gb-nbg1-1:~# netstat -antp
Active Internet connections (servers and established)
Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name    
tcp        0      0 127.0.0.53:53           0.0.0.0:*               LISTEN      582/systemd-resolve 
tcp        0      0 127.0.0.1:5432          0.0.0.0:*               LISTEN      4146/postgres       
tcp        0      0 0.0.0.0:80              0.0.0.0:*               LISTEN      184589/nginx: maste 
tcp        0      0 127.0.0.54:53           0.0.0.0:*               LISTEN      582/systemd-resolve 
tcp6       0      0 ::1:5432                :::*                    LISTEN      4146/postgres       
tcp6       0      0 :::22                   :::*                    LISTEN      1/init              
tcp6       0      0 :::80                   :::*                    LISTEN      184589/nginx: maste 
tcp6       0      0 ::1:35248               ::1:5432                ESTABLISHED 165697/mattermost   
tcp6       0      0 XXX:22      XXX:49322    ESTABLISHED 183797/sshd: root@p 
tcp6       0      0 ::1:5432                ::1:35238               ESTABLISHED 165703/postgres: 16 
tcp6       0      0 ::1:5432                ::1:35248               ESTABLISHED 165704/postgres: 16 
tcp6       0      0 ::1:35238               ::1:5432                ESTABLISHED 165697/mattermost   
tcp6       0    712 XXX:22      XXX:49355    ESTABLISHED 185255/sshd: root@p 
root@ubuntu-4gb-nbg1-1:~# 

I’ve completely reset the server and did everything again. Same issue persisted. When checking the logs, it seemed to be a postgres access issue with:

Error: failed to initialize platform: cannot create store: failed to apply database migrations: pq: permission denied for schema public
{"timestamp":"2024-08-23 12:15:43.090 Z","level":"error","msg":"failed to initialize platform: cannot create store: failed to apply database migrations: pq: permission denied for schema public","caller":"commands/server.go:76"}

That was resolved by:

Thanks to Alexander this is solved.
for PSQL 15 you need extra grants for the user:

GRANT ALL ON DATABASE mattermost TO mmuser;
ALTER DATABASE mattermost OWNER TO mmuser;
GRANT USAGE, CREATE ON SCHEMA PUBLIC TO mmuser;

Great to see you are unblocked.

This guidance is provided in our documentation Prepare your Mattermost database - Mattermost documentation