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
agnivade
(Agniva De Sarker)
August 23, 2024, 5:34am
2
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
agnivade
(Agniva De Sarker)
August 23, 2024, 8:44am
4
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;
Ubuntu 20.04 LTS HWE
Summary
Starting (through systemd) Mattermost based on PostgreSQL 15(on the same server) stops immediately on this error:
{“timestamp”:“2022-10-18 18:40:27.382 +02:00”,“level”:“fatal”,“msg”:“Failed to apply database migrations.”,“caller”:“sqlstore/store.go:166”,“error”:“pq: permission denied for schema public”}
Steps to reproduce
Following the installation guide.
Starting Mattermost like: systemctl start mattermost.service
Immediately ending.
Expected behavior
Instal…
nab-77
(Neil B)
August 28, 2024, 12:39pm
7
Great to see you are unblocked.
This guidance is provided in our documentation Prepare your Mattermost database - Mattermost documentation