valheim-server-docker icon indicating copy to clipboard operation
valheim-server-docker copied to clipboard
verified publisher icon lloesche

Server stop working at fixed hour everyday

Open Nicbobbo6 opened this issue 1 year ago • 18 comments

Hello, I've been using this container since some times without problem, but recently i faced a bug. Every day at 5:00, my server stop responding and i have to restart the container. Please find my docker compose and the logs of the container :

May 26 04:45:15 supervisord: valheim-updater OK May 26 04:45:15 supervisord: valheim-updater Waiting for client config...OK May 26 04:45:15 supervisord: valheim-updater Waiting for user info... May 26 04:45:21 supervisord: valheim-updater OK May 26 04:45:21 supervisord: valheim-updater Update state (0x3) reconfiguring, progress: 0.00 (0 / 0) May 26 04:45:21 supervisord: valheim-updater Update state (0x5) verifying install, progress: 16.18 (379578661 / 2346408748) May 26 04:45:21 supervisord: valheim-updater Update state (0x5) verifying install, progress: 47.83 (1122265701 / 2346408748) May 26 04:45:21 supervisord: valheim-updater Update state (0x5) verifying install, progress: 91.02 (2135610149 / 2346408748) May 26 04:45:21 supervisord: valheim-updater Success! App '896660' fully installed. May 26 04:45:21 supervisord: valheim-updater .d..t...... ./ May 26 04:45:21 supervisord: valheim-updater INFO - Valheim Server is already the latest version May 26 04:46:12 supervisord: valheim-server 05/26/2024 04:46:12: Connections 0 ZDOS:652484 sent:0 recv:0 May 26 04:56:12 supervisord: valheim-server 05/26/2024 04:56:12: Connections 0 ZDOS:652484 sent:0 recv:0 May 26 05:00:01 CRON[24563]: pam_unix(cron:session): session opened for user valheim(uid=1003) by (uid=0) May 26 05:00:01 CRON[24562]: pam_unix(cron:session): session opened for user valheim(uid=1003) by (uid=0) May 26 05:00:01 CRON[24564]: pam_unix(cron:session): session opened for user valheim(uid=1003) by (uid=0) May 26 05:00:01 CRON[24565]: (valheim) CMD ([ -f "/var/run/valheim/valheim-updater.pid" ] && kill -HUP $(cat /var/run/valheim/valheim-updater.pid)) May 26 05:00:01 CRON[24566]: (valheim) CMD (/usr/local/bin/valheim-is-idle && /usr/local/bin/supervisorctl restart valheim-server) May 26 05:00:01 CRON[24567]: (valheim) CMD ([ -f "/var/run/valheim/valheim-backup.pid" ] && kill -HUP $(cat /var/run/valheim/valheim-backup.pid)) May 26 05:00:01 CRON[24564]: pam_unix(cron:session): session closed for user valheim May 26 05:00:01 CRON[24563]: pam_unix(cron:session): session closed for user valheim 2024-05-26 05:00:01,840 INFO waiting for valheim-server to stop May 26 05:00:01 supervisord: valheim-server DEBUG - [102] - Received signal to shut down valheim-server May 26 05:00:01 supervisord: valheim-server INFO - Shutting down Valheim server with PID 106 May 26 05:00:01 supervisord: valheim-server DEBUG - [102] - Waiting for Valheim Server with PID 106 to shut down May 26 05:00:01 supervisord: valheim-server 05/26/2024 05:00:01: Game - OnApplicationQuit May 26 05:00:01 supervisord: valheim-server Am I Host? True May 26 05:00:01 supervisord: valheim-server 05/26/2024 05:00:01: Available space to current user: 1592758517760. Saving is blocked if below: 63509574 bytes. Warnings are given if below: 127019148 May 26 05:00:01 supervisord: valheim-server 05/26/2024 05:00:01: Shutting down May 26 05:00:01 supervisord: valheim-server 05/26/2024 05:00:01: ZNet Shutdown May 26 05:00:02 supervisord: valheim-server 05/26/2024 05:00:02: PrepareSave: clone done in 116ms May 26 05:00:02 supervisord: valheim-server 05/26/2024 05:00:02: PrepareSave: ZDOExtraData.PrepareSave done in 125 ms May 26 05:00:02 supervisord: valheim-server 05/26/2024 05:00:02: World save writing starting May 26 05:00:02 supervisord: valheim-server 05/26/2024 05:00:02: World save writing started 2024-05-26 05:00:03,840 INFO waiting for valheim-server to stop May 26 05:00:04 supervisord: valheim-server 05/26/2024 05:00:04: Saved 652484 ZDOs May 26 05:00:04 supervisord: valheim-server 05/26/2024 05:00:04: World save writing finishing May 26 05:00:04 supervisord: valheim-updater DEBUG - [42] - Received signal to check for update May 26 05:00:04 supervisord: valheim-updater DEBUG - [42] - Kernel: Linux b1b4b426ec7e 6.1.0-0.deb11.13-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.1.55-1~bpo11+1 (2023-10-08) x86_64 GNU/Linux May 26 05:00:04 supervisord: valheim-updater DEBUG - [42] - Found CPU with 4207.789 MHz May 26 05:00:04 supervisord: valheim-updater DEBUG - [42] - Memory total/free/available: 16242944/977660/6134892 May 26 05:00:04 supervisord: valheim-updater DEBUG - [42] - Storage configuration: May 26 05:00:04 supervisord: valheim-updater Filesystem Size Used Avail Use% Mounted on May 26 05:00:04 supervisord: valheim-updater overlay 109G 27G 76G 26% / May 26 05:00:04 supervisord: valheim-updater /dev/md0 11T 9.4T 1.5T 87% /data May 26 05:00:04 supervisord: valheim-updater overlay / overlay rw,relatime,lowerdir=/var/lib/docker/overlay2/l/S2VIO4MSDAY64ZCYMZ3LPS4XV5:/var/lib/docker/overlay2/l/4KZJG6B6YGWCVKOSOZO2V4EMKL:/var/lib/docker/overlay2/l/7KWIOSBH7NIFDMNPUFKCK7EJ5M:/var/lib/docker/overlay2/l/CQ3GNU2MF3YKTQDIRY2SQXO6AE:/var/lib/docker/overlay2/l/XKAPKSI37OZI22SRXXF4EZ7XNQ:/var/lib/docker/overlay2/l/ZDF7UZKTPURLIRO3SHLNIMO6PQ:/var/lib/docker/overlay2/l/MXYIO6XQAHKOWIWMIHA7C3VAOU:/var/lib/docker/overlay2/l/6IFIDVUYDHOGWXUAVZAVPKYXD6,upperdir=/var/lib/docker/overlay2/0a6eb3b4023e5379881db68dfc0dac655da68d47f46f07ee955c2b903cf78922/diff,workdir=/var/lib/docker/overlay2/0a6eb3b4023e5379881db68dfc0dac655da68d47f46f07ee955c2b903cf78922/work 0 0 May 26 05:00:04 supervisord: valheim-updater /dev/md0 /config ext4 rw,relatime,stripe=384,jqfmt=vfsv0,usrjquota=aquota.user,grpjquota=aquota.group 0 0 May 26 05:00:04 supervisord: valheim-updater /dev/md0 /data ext4 rw,relatime,stripe=384,jqfmt=vfsv0,usrjquota=aquota.user,grpjquota=aquota.group 0 0 May 26 05:00:04 supervisord: valheim-server 05/26/2024 05:00:04: World save writing finished May 26 05:00:04 supervisord: valheim-updater DEBUG - [42] - No players connected to Valheim server May 26 05:00:04 supervisord: valheim-updater INFO - Downloading/updating/validating Valheim server from Steam May 26 05:00:04 supervisord: valheim-server 05/26/2024 05:00:04: World saved ( 2297.58ms ) May 26 05:00:04 supervisord: valheim-server 05/26/2024 05:00:04: Considering autobackup. World time: 63829.58, short time: 7200, long time: 43200, backup count: 4 May 26 05:00:04 supervisord: valheim-server 05/26/2024 05:00:04: No autobackup needed yet... May 26 05:00:04 supervisord: valheim-server 05/26/2024 05:00:04: Unloading unused assets May 26 05:00:04 supervisord: valheim-server Unloading 0 Unused Serialized files (Serialized files now loaded: 1135) May 26 05:00:04 supervisord: valheim-server 05/26/2024 05:00:04: Sending disconnect msg May 26 05:00:04 supervisord: valheim-server ZPlayFabMatchmaking::UnregisterServer - unregistering server now. State: Uninitialized May 26 05:00:04 supervisord: valheim-server 05/26/2024 05:00:04: Disposing socket May 26 05:00:04 supervisord: valheim-server 05/26/2024 05:00:04: Stopping listening socket May 26 05:00:04 supervisord: valheim-server 05/26/2024 05:00:04: Last socket, unregistering callback May 26 05:00:04 supervisord: valheim-server 05/26/2024 05:00:04: ZSteamSocket UnregisterGlobalCallbacks, existing sockets:0 May 26 05:00:04 supervisord: valheim-server 05/26/2024 05:00:04: Stopping build thread 2024-05-26 05:00:05,840 INFO waiting for valheim-server to stop May 26 05:00:06 supervisord: valheim-updater Redirecting stderr to '/home/valheim/Steam/logs/stderr.txt' May 26 05:00:06 supervisord: valheim-updater Logging directory: '/home/valheim/Steam/logs' May 26 05:00:06 supervisord: valheim-updater [ 0%] Checking for available updates... May 26 05:00:06 supervisord: valheim-updater [----] Verifying installation... May 26 05:00:06 supervisord: valheim-updater UpdateUI: skip show logoSteam Console Client (c) Valve Corporation - version 1716584438 May 26 05:00:06 supervisord: valheim-updater -- type 'quit' to exit -- May 26 05:00:06 supervisord: valheim-updater Loading Steam API... May 26 05:00:06 supervisord: valheim-updater OK May 26 05:00:06 supervisord: valheim-updater May 26 05:00:06 supervisord: valheim-updater Connecting anonymously to Steam Public... May 26 05:00:07 supervisord: valheim-server Unloading 0 unused Assets to reduce memory usage. Loaded Objects now: 195844. May 26 05:00:07 supervisord: valheim-server Total: 221.370233 ms (FindLiveObjects: 11.328163 ms CreateObjectMapping: 13.666005 ms MarkObjects: 196.109468 ms DeleteObjects: 0.265930 ms) May 26 05:00:07 supervisord: valheim-server Setting up 4 worker threads for Enlighten. 2024-05-26 05:00:07,840 INFO waiting for valheim-server to stop May 26 05:00:07 supervisord: valheim-server DEBUG - [102] - Waiting for Valheim Server with PID 106 to shut down May 26 05:00:07 supervisord: valheim-server 05/26/2024 05:00:07: Steam manager on destroy May 26 05:00:08 supervisord: valheim-updater OK May 26 05:00:08 supervisord: valheim-updater Waiting for client config...OK May 26 05:00:08 supervisord: valheim-updater Waiting for user info... May 26 05:00:08 supervisord: valheim-server 05/26/2024 05:00:08: ZNet OnDestroy May 26 05:00:08 supervisord: valheim-server 05/26/2024 05:00:08: Net scene destroyed May 26 05:00:08 supervisord: valheim-server Memory Statistics: May 26 05:00:08 supervisord: valheim-server [ALLOC_TEMP_TLS] TLS Allocator May 26 05:00:08 supervisord: valheim-server StackAllocators : May 26 05:00:08 supervisord: valheim-server [ALLOC_TEMP_MAIN] May 26 05:00:08 supervisord: valheim-server Peak usage frame count: [0-1.0 KB]: 2235865 frames, [1.0 KB-2.0 KB]: 3 frames, [2.0 KB-4.0 KB]: 11 frames, [4.0 KB-8.0 KB]: 7 frames, [8.0 KB-16.0 KB]: 32 frames, [16.0 KB-32.0 KB]: 1914013 frames, [32.0 KB-64.0 KB]: 4 frames, [64.0 KB-128.0 KB]: 360 frames, [128.0 KB-256.0 KB]: 1 frames, [256.0 KB-0.5 MB]: 26 frames, [2.0 MB-4.0 MB]: 1 frames, [4.0 MB-8.0 MB]: 20 frames May 26 05:00:08 supervisord: valheim-server Initial Block Size 4.0 MB May 26 05:00:08 supervisord: valheim-server Current Block Size 7.6 MB May 26 05:00:08 supervisord: valheim-server Peak Allocated Bytes 7.6 MB May 26 05:00:08 supervisord: valheim-server Overflow Count 129 May 26 05:00:08 supervisord: valheim-server [ALLOC_TEMP_Background Job.worker 4] May 26 05:00:08 supervisord: valheim-server Initial Block Size 32.0 KB May 26 05:00:08 supervisord: valheim-server Current Block Size 32.0 KB May 26 05:00:08 supervisord: valheim-server Peak Allocated Bytes 168 B May 26 05:00:08 supervisord: valheim-server Overflow Count 0 May 26 05:00:08 supervisord: valheim-server [ALLOC_TEMP_Loading.PreloadManager]

docker_compose services: valheim: image: lloesche/valheim-server:latest restart: unless-stopped container_name: valheim-server ports: - 2456:2456/udp - 2457:2457/udp environment: - PUID=1003 - PGID=1003 - SERVER_PASS=dinoclub123 - SERVER_NAME=Serveur de Nico - SERVER_ARGS=-modifier portals casual -modifier deathpenalty casual volumes: - /srv/dev-disk-by-uuid-3038bdf3-cf9e-48e5-85e5-08090b6e17fe/Homes/docker/valheim/config:/config/ - /srv/dev-disk-by-uuid-3038bdf3-cf9e-48e5-85e5-08090b6e17fe/Homes/docker/valheim/data:/data/

Nicbobbo6 avatar May 26 '24 13:05 Nicbobbo6

Hello all,

Yeah, I have the same issue at 5am with the automatic restart of the server, it seems that only fails with the restart of the 5 am, because during previous hours without players it restart the servers to update it without issues: image

Regards, Tranko.

tranko1 avatar May 28 '24 09:05 tranko1

+1, exactly the same issue, server does not restart at 5am.

Tr4il avatar May 28 '24 17:05 Tr4il

I am having the same issue. Restart causes server to fail.

Dunny88 avatar Jun 02 '24 06:06 Dunny88

Same issue here, can we turn the restart off?

dnbrainwash avatar Jun 05 '24 17:06 dnbrainwash

Same issue here, can we turn the restart off?

You can. I set the UPDATE_CRON and RESTART_CRON to an empty string to stop all automatic restarts. This has been working for me so far.

Interestingly setting only UPDATE_CRON did not fix it so this issue appears to be with any restart not just for updates. I'm still trying to figure out why.

bubylou avatar Jun 05 '24 21:06 bubylou

I am also seeing the same issue. Server stops at 5am (UTC time).

Dimand avatar Jul 24 '24 07:07 Dimand

I am still having the exact same problem ...

MartenBE avatar Oct 11 '24 08:10 MartenBE

I'm having the same problem.

DarKZoNe482 avatar Dec 30 '24 13:12 DarKZoNe482

@lloesche - What's the likelihood of investigation into this issue? This represents a fairly significant quality-of-life opportunity that benefits maintainers of servers. As-is, the community is left to disable a core feature or create disparate workarounds.

Knaledge avatar Feb 05 '25 05:02 Knaledge

My server worked fine for months, and then this week started doing this.

chrisl8 avatar Feb 19 '25 14:02 chrisl8

My theory at the moment is that, for some reason specific to the 5am restart, when it tries to stop the server, it becomes <defunct> instead of going away, and then the scripts are stuck, waiting for a zombie process to die:

root@8fe4fb0df93a:/# ps -ef
UID          PID    PPID  C STIME TTY          TIME CMD
root           1       0  0 Feb18 ?        00:00:27 /usr/bin/python3 /usr/local/bin/supervisord -c /usr/local/etc/supervisord.conf
root          27       1  0 Feb18 ?        00:00:00 /usr/local/sbin/syslogd -n -S -t -O -
root          28       1  0 Feb18 ?        00:00:00 /usr/sbin/cron -f
valheim       59       1  0 Feb18 ?        00:00:07 /bin/bash /usr/local/bin/valheim-updater
valheim      101       1  0 Feb18 ?        00:00:03 /bin/bash /usr/local/bin/valheim-backup
valheim      236       1  0 Feb18 ?        00:00:00 [valheim-server] <defunct>
root       27461      28  0 05:00 ?        00:00:00 /usr/sbin/CRON -f
valheim    27464   27461  0 05:00 ?        00:00:00 /usr/bin/python3 /usr/local/bin/supervisorctl restart valheim-server

Can others here exec into their docker container and post the output of the ps -ef command from inside of the container?

chrisl8 avatar Feb 19 '25 15:02 chrisl8

Same again this morning, defunct processes.

root@2a69723a9bc6:/# ps -ef
UID          PID    PPID  C STIME TTY          TIME CMD
root           1       0  0 Feb19 ?        00:00:29 /usr/bin/python3 /usr/local/bin/supervisord -c /usr/local/etc/supervisord.conf
root          26       1  0 Feb19 ?        00:00:00 /usr/local/sbin/syslogd -n -S -t -O -
root          27       1  0 Feb19 ?        00:00:00 /usr/sbin/cron -f
root          58       1  0 Feb19 ?        00:00:08 /bin/bash /usr/local/bin/valheim-updater
root         100       1  0 Feb19 ?        00:00:03 /bin/bash /usr/local/bin/valheim-backup
root         233       1  0 Feb19 ?        00:00:00 [valheim-server] <defunct>
root         242       1  0 Feb19 ?        00:00:00 [valheim-server] <defunct>
root       32247      27  0 05:00 ?        00:00:00 /usr/sbin/CRON -f
root       32250   32247  0 05:00 ?        00:00:00 /usr/bin/python3 /usr/local/bin/supervisorctl restart valheim-server

I also tried running as root instead of PID in case that helps, but it did not.

As a comparison, here is what it looks like when it is healthy:

root@937355b756df:/# ps -ef
UID          PID    PPID  C STIME TTY          TIME CMD
root           1       0  0 09:19 ?        00:00:00 /usr/bin/python3 /usr/local/bin/supervisord -c /usr/local/etc/supervisord.conf
root          26       1  0 09:19 ?        00:00:00 /usr/local/sbin/syslogd -n -S -t -O -
root          27       1  0 09:19 ?        00:00:00 /usr/sbin/cron -f
root          53       1  0 09:19 ?        00:00:00 /bin/bash /usr/local/bin/valheim-updater
root         100       1  0 09:19 ?        00:00:00 /bin/bash /usr/local/bin/valheim-backup
root         255       1  0 09:20 ?        00:00:00 /bin/bash /usr/local/bin/valheim-server
root         260     255 34 09:20 ?        00:02:21 /opt/valheim/bepinex/valheim_server.x86_64 -nographics -batchmode -name Lofland -port 2456 -world Yggdrasil -public
root         262     260  0 09:20 ?        00:00:00 /bin/bash /usr/local/bin/valheim-server
root         265     262  0 09:20 ?        00:00:00 /usr/local/bin/valheim-logfilter -logtostderr -v 2
root         466       0  0 09:23 pts/0    00:00:00 bash
root         554      53  0 09:26 ?        00:00:00 sleep 9
root         556     100  0 09:26 ?        00:00:00 sleep 20
root         557     466  0 09:27 pts/0    00:00:00 ps -ef

Another note: After stopping the container, or trying to, this is the state:

❮ docker exec -it valheim bash
root@937355b756df:/# ps -ef
UID          PID    PPID  C STIME TTY          TIME CMD
root           1       0  0 09:19 ?        00:00:00 /usr/bin/python3 /usr/local/bin/supervisord -c /usr/local/etc/supervisord.conf
root          26       1  0 09:19 ?        00:00:00 /usr/local/sbin/syslogd -n -S -t -O -
root          27       1  0 09:19 ?        00:00:00 /usr/sbin/cron -f
root          53       1  0 09:19 ?        00:00:00 /bin/bash /usr/local/bin/valheim-updater
root         100       1  0 09:19 ?        00:00:00 /bin/bash /usr/local/bin/valheim-backup
root         255       1  0 09:20 ?        00:00:00 [valheim-server] <defunct>
root         262       1  0 09:20 ?        00:00:00 [valheim-server] <defunct>
root        1398     100  0 09:57 ?        00:00:00 sleep 20
root        1400      53  0 09:57 ?        00:00:00 sleep 9
root        1401       0  1 09:57 pts/0    00:00:00 bash
root        1407    1401  0 09:57 pts/0    00:00:00 ps -ef
root@937355b756df:/#

and Docker has to forcefully kill the container because of this. So it seems like the server stop process is failing to stop valheim in a way that does not leave behind zombie processes.

Why did this work fine for months and then start one day? Why is this pattern the same for others.

It isn't a new Valheim update, as it has been happening since at least May of 2024.

I am going to try adding init: true to my compose file like so:

services:
  valheim:
    image: ghcr.io/lloesche/valheim-server
    init: true

next to see if this helps. https://docs.docker.com/reference/compose-file/services/#init

Update My server survived the 5am restart this morning. My initial hope is that adding init: true to the compose file worked, but it has also worked in the past, so this could be a one time fluke. I will report back if it fails again. I will try to report back if it continues to work as well, but feel free to ping me here if you don't see more updates from me in the future.

chrisl8 avatar Feb 20 '25 15:02 chrisl8

I solved this problem for myself by adding init: true to my compose file like so:

services:
  valheim:
    image: ghcr.io/lloesche/valheim-server
    init: true

https://docs.docker.com/reference/compose-file/services/#init

My server has survived the 5am restart every morning since I did this.

I would be interested to know if this helps anyone else.

chrisl8 avatar Feb 28 '25 17:02 chrisl8

Unfortunately, init: true didn't fix it for me. Proceeded to just disable the restarting

Firestar99 avatar Mar 04 '25 13:03 Firestar99

In #724 and #725 I made it so the valheim-server runs in a dedicated process group and on restart it kills the entire group instead of just the server process. This can help in case the server spawns its own child processes and doesn't cleanly close them. Although I have not observed any such behaviour.

In #723 I added tini as PID 1, in hopes for it to be a better process reaper than supervisord. I still can't reproduce the issue on my system. Please test and let me know if this changes the issue. It would also be interesting to see if you can manually produce the problem.

To do so, manually exec into the container (docker exec -it valheim-server /bin/bash) and run:

ps ax | cat
/usr/local/bin/supervisorctl restart valheim-server
ps ax | cat

and post the output here.

It should look something like this:

(base) lukas@blackhole:~/repo/valheim-server-docker$ docker exec -it valheim-server /bin/bash
root@552d36bdfa35:/# ps ax | cat
    PID TTY      STAT   TIME COMMAND
      1 pts/0    Ss     0:00 /usr/bin/tini -- /usr/local/bin/supervisord -c /usr/local/etc/supervisord.conf
     24 pts/0    S+     1:24 /usr/bin/python3 /usr/local/bin/supervisord -c /usr/local/etc/supervisord.conf
     25 pts/0    S      0:00 /usr/local/sbin/syslogd -n -S -t -O -
     26 pts/0    S      0:00 /usr/sbin/cron -f
     37 pts/0    S      0:00 /bin/bash /usr/local/bin/valheim-updater
     74 pts/0    S      0:00 /bin/bash /usr/local/bin/valheim-backup
   2179 pts/0    S      0:00 sleep 20
   2212 pts/0    S      0:00 /bin/bash /usr/local/bin/valheim-server
   2216 pts/0    Sl     0:14 /opt/valheim/server/valheim_server.x86_64 -nographics -batchmode -name My Server -port 2456 -world Neotopia -public 1 -password secret -modifier portals casual -modifier deathpenalty casual
   2218 pts/0    S      0:00 /bin/bash /usr/local/bin/valheim-server
   2220 pts/0    Sl     0:00 /usr/local/bin/valheim-logfilter -logtostderr -v 2
   2343 pts/0    S      0:00 sleep 9
   2345 pts/1    Ss     0:00 /bin/bash
   2351 pts/1    R+     0:00 ps ax
   2352 pts/1    S+     0:00 cat
root@552d36bdfa35:/# /usr/local/bin/supervisorctl restart valheim-server
valheim-server: stopped
valheim-server: started
root@552d36bdfa35:/# ps ax | cat
    PID TTY      STAT   TIME COMMAND
      1 pts/0    Ss     0:00 /usr/bin/tini -- /usr/local/bin/supervisord -c /usr/local/etc/supervisord.conf
     24 pts/0    S+     1:30 /usr/bin/python3 /usr/local/bin/supervisord -c /usr/local/etc/supervisord.conf
     25 pts/0    S      0:00 /usr/local/sbin/syslogd -n -S -t -O -
     26 pts/0    S      0:00 /usr/sbin/cron -f
     37 pts/0    S      0:00 /bin/bash /usr/local/bin/valheim-updater
     74 pts/0    S      0:00 /bin/bash /usr/local/bin/valheim-backup
   2345 pts/1    Ss     0:00 /bin/bash
   2354 pts/0    S      0:00 sleep 20
   2375 pts/0    S      0:00 /bin/bash /usr/local/bin/valheim-server
   2379 pts/0    Sl     0:13 /opt/valheim/server/valheim_server.x86_64 -nographics -batchmode -name My Server -port 2456 -world Neotopia -public 1 -password secret -modifier portals casual -modifier deathpenalty casual
   2381 pts/0    S      0:00 /bin/bash /usr/local/bin/valheim-server
   2384 pts/0    Sl     0:00 /usr/local/bin/valheim-logfilter -logtostderr -v 2
   2476 pts/0    S      0:00 sleep 9
   2477 pts/1    R+     0:00 ps ax
   2478 pts/1    S+     0:00 cat

There is a PR open (#717) that claims to fix the issue by adding quotes around $SERVER_ARGS. I tried running the server with the same SERVER_ARGS=-modifier portals casual -modifier deathpenalty casual as @Nicbobbo6 and set the 5AM restart cron to restart the server every minute, without every encountering the issue. So as mentioned I'm unable to reproducing the problem.

For some background, $SERVER_ARGS is not quoted on purpose. If we would add quotes then all server args would be passed to valheim-server as a single argument. See this demo script output:

root@552d36bdfa35:~# echo $SERVER_ARGS
-modifier portals casual -modifier deathpenalty casual
root@552d36bdfa35:~# cat test.sh
#!/bin/bash
echo $1  # print the first argument
echo $2  # print the second argument
echo $3  # print the third argument
root@552d36bdfa35:~# ./test.sh $SERVER_ARGS
-modifier
portals
casual
root@552d36bdfa35:~# ./test.sh "$SERVER_ARGS"
-modifier portals casual -modifier deathpenalty casual


root@552d36bdfa35:~#

Which is why I haven't merged the PR yet. I'm afraid it might break other users setups by turning what is supposed to be multiple server arguments into a single arg.

lloesche avatar Mar 21 '25 23:03 lloesche

Hello @lloesche ,

I have the same problem. The server goes down at 5:10. Here is my docker-compose.yaml:

cat docker-compose.yaml
services:
  valheim:
    image: ghcr.io/lloesche/valheim-server
    cap_add:
      - sys_nice
    volumes:
      - /mnt/main/valheim-23-03-25/config:/config
      - /mnt/main/valheim-23-03-25/data:/opt/valheim
    ports:
      - "2456-2458:2456-2458/udp"
      - "9011:9001/tcp"
    env_file:
      - /mnt/main/valheim-23-03-25/valheim.env
    restart: always
    stop_grace_period: 2m

here is my valheim.env :

SERVER_NAME=Muninn
WORLD_NAME=Muninn
SERVER_PASS=XXXXXXXXXX
SERVER_PUBLIC=true
DISCORD_WEBHOOK=XXXXXXXXXXXXXXXX
STATUS_HTTP=true
VALHEIM_PLUS=true
SUPERVISOR_HTTP=true
TZ=Europe/Brussels
PRE_BOOTSTRAP_HOOK=curl -sfSL -X POST -H "Content-Type: application/json" -d "{\"username\":\"Valheim\",\"content\":\"[$(date +'%b %d %T')] Valheim Server is staring.\"}" "$DISCORD_WEBHOOK"
PRE_SERVER_SHUTDOWN_HOOK=curl -sfSL -X POST -H "Content-Type: application/json" -d "{\"username\":\"Valheim\",\"content\":\"[$(date +'%b %d %T')] Stopping Valheim Server\"}" "$DISCORD_WEBHOOK"
POST_SERVER_LISTENING_HOOK=curl -sfSL -X POST -H "Content-Type: application/json" -d "{\"username\":\"Valheim\",\"content\":\"[$(date +'%b %d %T')] Valheim Server ready.\"}" "$DISCORD_WEBHOOK"
POST_RESTART_HOOK=curl -sfSL -X POST -H "Content-Type: application/json" -d "{\"username\":\"Valheim\",\"content\":\"[$(date +'%b %d %T')] Valheim Server restarted by Updater.\"}" "$DISCORD_WEBHOOK"
VALHEIM_LOG_FILTER_CONTAINS_Spawned=Got character ZDOID from

here is the return from the docker ps command

754db74b8834   ghcr.io/lloesche/valheim-server               "/usr/local/sbin/boo…"   2 days ago     Up 23 hours                  80/tcp, 0.0.0.0:2456-2458->2456-2458/udp, :::2456-2458->2456-2458/udp, 0.0.0.0:9011->9001/tcp, :::9011->9001/tcp

here's the return from the docker log command

Mar 26 05:00:52 supervisord: valheim-updater DEBUG - [18628] - Local ValheimPlus archive is identical to remote archive and was successfully installed - no update required
Mar 26 05:05:01 CRON[18733]: pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)
Mar 26 05:05:01 CRON[18734]: (root) CMD ([ -f "/var/run/valheim/valheim-backup.pid" ] && kill -HUP $(cat /var/run/valheim/valheim-backup.pid))
Mar 26 05:05:01 CRON[18733]: pam_unix(cron:session): session closed for user root
Mar 26 05:05:16 supervisord: valheim-server [Info   :Valheim Plus] Saved 12836 map points to disk.
Mar 26 05:05:16 supervisord: valheim-server 03/26/2025 05:05:16: Console: [Info   :Valheim Plus] Saved 12836 map points to disk.
Mar 26 05:05:18 supervisord: valheim-backup DEBUG - [103] - Received signal to backup world
Mar 26 05:05:18 supervisord: valheim-backup INFO - Backing up Valheim server worlds to /config/backups/worlds-20250326-050518.zip
Mar 26 05:05:18 supervisord: valheim-backup   adding: config/worlds_local/ (stored 0%)
Mar 26 05:05:18 supervisord: valheim-backup   adding: config/worlds_local/Muninn.fwl
Mar 26 05:05:18 supervisord: valheim-backup  (deflated 8%)
Mar 26 05:05:18 supervisord: valheim-backup   adding: config/worlds_local/Muninn.fwl.old (deflated 8%)
Mar 26 05:05:18 supervisord: valheim-backup   adding: config/worlds_local/Muninn.db.old
Mar 26 05:05:19 supervisord: valheim-backup  (deflated 44%)
Mar 26 05:05:19 supervisord: valheim-backup   adding: config/worlds_local/Muninn.db
Mar 26 05:05:19 supervisord: valheim-backup  (deflated 44%)
Mar 26 05:05:19 supervisord: valheim-backup INFO - Removing backups older than 3 days
Mar 26 05:10:01 CRON[18845]: pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)
Mar 26 05:10:01 CRON[18846]: (root) CMD (/usr/local/bin/valheim-is-idle && /usr/local/bin/supervisorctl restart valheim-server)
2025-03-26 05:10:03,137 INFO waiting for valheim-server to stop
Mar 26 05:10:03 supervisord: valheim-server DEBUG - [174] - Received signal to shut down valheim-server
2025-03-26 05:10:05,137 INFO waiting for valheim-server to stop
2025-03-26 05:10:07,137 INFO waiting for valheim-server to stop
Mar 26 05:10:07 supervisord: valheim-server INFO - Shutting down Valheim server with PID 179
Mar 26 05:10:07 supervisord: valheim-server DEBUG - [174] - Waiting for Valheim Server with PID 179 to shut down
Mar 26 05:10:07 supervisord: valheim-server 03/26/2025 05:10:07: Console: [Info   : Unity Log] 03/26/2025 05:10:07: Game - OnApplicationQuit
Mar 26 05:10:07 supervisord: valheim-server 03/26/2025 05:10:07: Game - OnApplicationQuit
Mar 26 05:10:07 supervisord: valheim-server 03/26/2025 05:10:07: Console: [Info   : Unity Log] Am I Host? True
Mar 26 05:10:07 supervisord: valheim-server Am I Host? True
Mar 26 05:10:07 supervisord: valheim-server 03/26/2025 05:10:07: Console: [Info   : Unity Log] 03/26/2025 05:10:07: Available space to current user: 4225277886464. Saving is blocked if below: 14340100 bytes. Warnings are given if below: 28680200
Mar 26 05:10:07 supervisord: valheim-server 03/26/2025 05:10:07: Available space to current user: 4225277886464. Saving is blocked if below: 14340100 bytes. Warnings are given if below: 28680200
Mar 26 05:10:07 supervisord: valheim-server 03/26/2025 05:10:07: Console: [Info   : Unity Log] 03/26/2025 05:10:07: Shutting down
Mar 26 05:10:07 supervisord: valheim-server 03/26/2025 05:10:07: Shutting down
Mar 26 05:10:07 supervisord: valheim-server [Info   :Valheim Plus] Saved 12836 map points to disk.
Mar 26 05:10:07 supervisord: valheim-server 03/26/2025 05:10:07: Console: [Info   : Unity Log] 03/26/2025 05:10:07: Console: [Info   :Valheim Plus] Saved 12836 map points to disk.
Mar 26 05:10:07 supervisord: valheim-server 03/26/2025 05:10:07: Console: [Info   :Valheim Plus] Saved 12836 map points to disk.
Mar 26 05:10:07 supervisord: valheim-server 03/26/2025 05:10:07: Console: [Info   : Unity Log] 03/26/2025 05:10:07: ZNet Shutdown
Mar 26 05:10:07 supervisord: valheim-server 03/26/2025 05:10:07: ZNet Shutdown
Mar 26 05:10:07 supervisord: valheim-server 03/26/2025 05:10:07: Console: [Info   : Unity Log] 03/26/2025 05:10:07: PrepareSave: clone done in 18ms
Mar 26 05:10:07 supervisord: valheim-server 03/26/2025 05:10:07: PrepareSave: clone done in 18ms
Mar 26 05:10:07 supervisord: valheim-server 03/26/2025 05:10:07: Console: [Info   : Unity Log] 03/26/2025 05:10:07: PrepareSave: ZDOExtraData.PrepareSave done in 13 ms
Mar 26 05:10:07 supervisord: valheim-server 03/26/2025 05:10:07: PrepareSave: ZDOExtraData.PrepareSave done in 13 ms
Mar 26 05:10:07 supervisord: valheim-server 03/26/2025 05:10:07: World save writing starting
Mar 26 05:10:07 supervisord: valheim-server 03/26/2025 05:10:07: World save writing started
Mar 26 05:10:08 supervisord: valheim-server 03/26/2025 05:10:08: Saved 107590 ZDOs
Mar 26 05:10:08 supervisord: valheim-server 03/26/2025 05:10:08: World save writing finishing
Mar 26 05:10:08 supervisord: valheim-server 03/26/2025 05:10:08: World save writing finished
Mar 26 05:10:08 supervisord: valheim-server 03/26/2025 05:10:08: World saved ( 414.377ms )
Mar 26 05:10:08 supervisord: valheim-server 03/26/2025 05:10:08: Considering autobackup. World time: 44991.36, short time: 7200, long time: 43200, backup count: 4
Mar 26 05:10:08 supervisord: valheim-server 03/26/2025 05:10:08: No autobackup needed yet...
Mar 26 05:10:08 supervisord: valheim-server 03/26/2025 05:10:08: Console: [Info   : Unity Log] 03/26/2025 05:10:08: Unloading unused assets
Mar 26 05:10:08 supervisord: valheim-server 03/26/2025 05:10:08: Unloading unused assets
Mar 26 05:10:08 supervisord: valheim-server Unloading 0 Unused Serialized files (Serialized files now loaded: 18)
Mar 26 05:10:08 supervisord: valheim-server 03/26/2025 05:10:08: Console: [Info   : Unity Log] 03/26/2025 05:10:08: Sending disconnect msg
Mar 26 05:10:08 supervisord: valheim-server 03/26/2025 05:10:08: Sending disconnect msg
Mar 26 05:10:08 supervisord: valheim-server 03/26/2025 05:10:08: Console: [Info   : Unity Log] ZPlayFabMatchmaking::UnregisterServer - unregistering server now. State: Uninitialized
Mar 26 05:10:08 supervisord: valheim-server ZPlayFabMatchmaking::UnregisterServer - unregistering server now. State: Uninitialized
Mar 26 05:10:08 supervisord: valheim-server 03/26/2025 05:10:08: Console: [Info   : Unity Log] 03/26/2025 05:10:08: Disposing socket
Mar 26 05:10:08 supervisord: valheim-server 03/26/2025 05:10:08: Disposing socket
Mar 26 05:10:08 supervisord: valheim-server 03/26/2025 05:10:08: Console: [Info   : Unity Log] 03/26/2025 05:10:08: Stopping listening socket
Mar 26 05:10:08 supervisord: valheim-server 03/26/2025 05:10:08: Stopping listening socket
Mar 26 05:10:08 supervisord: valheim-server 03/26/2025 05:10:08: Console: [Info   : Unity Log] 03/26/2025 05:10:08: Last socket, unregistering callback
Mar 26 05:10:08 supervisord: valheim-server 03/26/2025 05:10:08: Last socket, unregistering callback
Mar 26 05:10:08 supervisord: valheim-server 03/26/2025 05:10:08: Console: [Info   : Unity Log] 03/26/2025 05:10:08: ZSteamSocket  UnregisterGlobalCallbacks, existing sockets:0
Mar 26 05:10:08 supervisord: valheim-server 03/26/2025 05:10:08: ZSteamSocket  UnregisterGlobalCallbacks, existing sockets:0
Mar 26 05:10:08 supervisord: valheim-server 03/26/2025 05:10:08: Console: [Info   : Unity Log] 03/26/2025 05:10:08: Stopping build thread
Mar 26 05:10:08 supervisord: valheim-server 03/26/2025 05:10:08: Stopping build thread
2025-03-26 05:10:09,137 INFO waiting for valheim-server to stop
Mar 26 05:10:10 supervisord: valheim-server Unloading 0 unused Assets to reduce memory usage. Loaded Objects now: 200192.
Mar 26 05:10:10 supervisord: valheim-server Total: 57.383193 ms (FindLiveObjects: 5.327499 ms CreateObjectMapping: 6.060442 ms MarkObjects: 45.795103 ms  DeleteObjects: 0.199690 ms)
Mar 26 05:10:10 supervisord: valheim-server 03/26/2025 05:10:10: Console: [Info   : Unity Log] 03/26/2025 05:10:10: ZNet OnDestroy
Mar 26 05:10:10 supervisord: valheim-server 03/26/2025 05:10:10: ZNet OnDestroy
Mar 26 05:10:10 supervisord: valheim-server 03/26/2025 05:10:10: Console: [Info   : Unity Log] 03/26/2025 05:10:10: Net scene destroyed
Mar 26 05:10:10 supervisord: valheim-server 03/26/2025 05:10:10: Net scene destroyed
Mar 26 05:10:10 supervisord: valheim-server 03/26/2025 05:10:10: Console: [Info   : Unity Log] 03/26/2025 05:10:10: Steam manager on destroy
Mar 26 05:10:10 supervisord: valheim-server 03/26/2025 05:10:10: Steam manager on destroy
2025-03-26 05:10:11,137 INFO waiting for valheim-server to stop
Mar 26 05:10:11 supervisord: valheim-server Memory Statistics:
Mar 26 05:10:11 supervisord: valheim-server [ALLOC_TEMP_TLS] TLS Allocator
Mar 26 05:10:11 supervisord: valheim-server   StackAllocators :
Mar 26 05:10:11 supervisord: valheim-server     [ALLOC_TEMP_MAIN]
Mar 26 05:10:11 supervisord: valheim-server       Peak usage frame count: [0-1.0 KB]: 218455 frames, [2.0 KB-4.0 KB]: 2 frames, [4.0 KB-8.0 KB]: 1190600 frames, [8.0 KB-16.0 KB]: 6 frames, [16.0 KB-32.0 KB]: 9 frames, [32.0 KB-64.0 KB]: 2 frames, [64.0 KB-128.0 KB]: 158231 frames, [256.0 KB-0.5 MB]: 137 frames, [0.5 MB-1.0 MB]: 2 frames, [2.0 MB-4.0 MB]: 1 frames, [4.0 MB-8.0 MB]: 15 frames
Mar 26 05:10:11 supervisord: valheim-server       Initial Block Size 4.0 MB
Mar 26 05:10:11 supervisord: valheim-server       Current Block Size 7.7 MB
Mar 26 05:10:11 supervisord: valheim-server       Peak Allocated Bytes 7.7 MB
Mar 26 05:10:11 supervisord: valheim-server       Overflow Count 163
Mar 26 05:10:11 supervisord: valheim-server     [ALLOC_TEMP_Loading.AsyncRead]
Mar 26 05:10:11 supervisord: valheim-server       Initial Block Size 64.0 KB
Mar 26 05:10:11 supervisord: valheim-server       Current Block Size 128.0 KB
Mar 26 05:10:11 supervisord: valheim-server       Peak Allocated Bytes 127.8 KB
Mar 26 05:10:11 supervisord: valheim-server       Overflow Count 0
Mar 26 05:10:11 supervisord: valheim-server     [ALLOC_TEMP_Loading.PreloadManager]
Mar 26 05:10:11 supervisord: valheim-server       Initial Block Size 256.0 KB
Mar 26 05:10:11 supervisord: valheim-server       Current Block Size 0.5 MB
Mar 26 05:10:11 supervisord: valheim-server       Peak Allocated Bytes 511.5 KB

As you can see, I redirected the supervisor to port 9011 because 9001 host was busy. When the server is running normally, the web supervisor is accessible. When it crashes at 5.10am, you get a blank page and the browser runs in a loop.

about the manual test

ps ax | cat
/usr/local/bin/supervisorctl restart valheim-server
ps ax | cat

    PID TTY      STAT   TIME COMMAND
      1 ?        Ss     0:01 /usr/bin/tini -- /usr/local/bin/supervisord -c /usr/local/etc/supervisord.conf
     31 ?        S      0:20 /usr/bin/python3 /usr/local/bin/supervisord -c /usr/local/etc/supervisord.conf
     32 ?        S      0:00 /usr/local/sbin/syslogd -n -S -t -O -
     33 ?        S      0:00 /usr/sbin/cron -f
     35 ?        S      0:09 python3 /usr/local/bin/valheim-status --update
     36 ?        S      0:00 /usr/local/bin/httpd -f -p 80 -h /opt/valheim/htdocs -c /config/httpd.conf
     58 ?        S      0:09 /bin/bash /usr/local/bin/valheim-updater
    103 ?        S      0:03 /bin/bash /usr/local/bin/valheim-backup
    174 ?        Z      0:00 [valheim-server] <defunct>
  18845 ?        S      0:00 /usr/sbin/CRON -f
  18846 ?        Ss     0:00 /usr/bin/python3 /usr/local/bin/supervisorctl restart valheim-server
  18968 ?        S      0:00 /usr/sbin/CRON -f
  19007 ?        S      0:00 /usr/sbin/CRON -f
  19260 ?        S      0:00 /usr/sbin/CRON -f
  19551 ?        S      0:00 /usr/sbin/CRON -f
  19842 ?        S      0:00 /usr/sbin/CRON -f
  19939 ?        S      0:00 /usr/sbin/CRON -f
  20134 ?        S      0:00 /usr/sbin/CRON -f
  20173 ?        S      0:00 /usr/sbin/CRON -f
  20328 ?        S      0:00 /usr/sbin/CRON -f
  20427 ?        S      0:00 /usr/sbin/CRON -f
  20716 ?        S      0:00 /usr/sbin/CRON -f
  21007 ?        S      0:00 /usr/sbin/CRON -f
  21106 ?        S      0:00 /usr/sbin/CRON -f
  21299 ?        S      0:00 /usr/sbin/CRON -f
  21340 ?        S      0:00 /usr/sbin/CRON -f
  21591 ?        S      0:00 /usr/sbin/CRON -f
  21882 ?        S      0:00 /usr/sbin/CRON -f
  22173 ?        S      0:00 /usr/sbin/CRON -f
  22272 ?        S      0:00 /usr/sbin/CRON -f
  22465 ?        S      0:00 /usr/sbin/CRON -f
  22506 ?        S      0:00 /usr/sbin/CRON -f
  22757 ?        S      0:00 /usr/sbin/CRON -f
  23048 ?        S      0:00 /usr/sbin/CRON -f
  23337 ?        S      0:00 /usr/sbin/CRON -f
  23434 ?        S      0:00 /usr/sbin/CRON -f
  23629 ?        S      0:00 /usr/sbin/CRON -f
  23668 ?        S      0:00 /usr/sbin/CRON -f
  23921 ?        S      0:00 /usr/sbin/CRON -f
  24212 ?        S      0:00 /usr/sbin/CRON -f
  24503 ?        S      0:00 /usr/sbin/CRON -f
  24600 ?        S      0:00 /usr/sbin/CRON -f
  24795 ?        S      0:00 /usr/sbin/CRON -f
  24834 ?        S      0:00 /usr/sbin/CRON -f
  25087 ?        S      0:00 /usr/sbin/CRON -f
  25378 ?        S      0:00 /usr/sbin/CRON -f
  25669 ?        S      0:00 /usr/sbin/CRON -f
  25766 ?        S      0:00 /usr/sbin/CRON -f
  25959 ?        S      0:00 /usr/sbin/CRON -f
  26000 ?        S      0:00 /usr/sbin/CRON -f
  26251 ?        S      0:00 /usr/sbin/CRON -f
  26542 ?        S      0:00 /usr/sbin/CRON -f
  26833 ?        S      0:00 /usr/sbin/CRON -f
  26932 ?        S      0:00 /usr/sbin/CRON -f
  27125 ?        S      0:00 /usr/sbin/CRON -f
  27166 ?        S      0:00 /usr/sbin/CRON -f
  27417 ?        S      0:00 /usr/sbin/CRON -f
  27708 ?        S      0:00 /usr/sbin/CRON -f
  27999 ?        S      0:00 /usr/sbin/CRON -f
  28096 ?        S      0:00 /usr/sbin/CRON -f
  28291 ?        S      0:00 /usr/sbin/CRON -f
  28330 ?        S      0:00 /usr/sbin/CRON -f
  28583 ?        S      0:00 /usr/sbin/CRON -f
  28874 ?        S      0:00 /usr/sbin/CRON -f
  29165 ?        S      0:00 /usr/sbin/CRON -f
  29262 ?        S      0:00 /usr/sbin/CRON -f
  29457 ?        S      0:00 /usr/sbin/CRON -f
  29496 ?        S      0:00 /usr/sbin/CRON -f
  29749 ?        S      0:00 /usr/sbin/CRON -f
  30000 pts/0    Ss     0:00 /bin/bash
  30007 ?        S      0:00 sleep 9
  30009 ?        S      0:00 sleep 20
  30010 pts/0    R+     0:00 ps ax
  30011 pts/0    S+     0:00 cat

Image Image

And on my side i don't have any $SERVER_ARGS i can't test that for u ;)

Have a good day,

JeremTS77 avatar Mar 26 '25 14:03 JeremTS77

My server stopped at the morning restart as well, so I did some testing.

Pretty easily reproducible with supervisorctl restart:

sh-5.1# ps -eo pid,ppid,stime,tty,time,stat,cmd --forest
  PID  PPID STIME TT           TIME STAT CMD
  165     0 12:00 pts/0    00:00:00 Ss   /bin/sh
  304   165 12:05 pts/0    00:00:00 R+    \_ ps -eo pid,ppid,stime,tty,time,stat,cmd --forest
    1     0 12:00 ?        00:00:00 Ss   /usr/bin/tini -- /usr/local/bin/supervisord -c /usr/local/etc/supervisord.conf
   24     1 12:00 ?        00:00:00 S    /usr/bin/python3 /usr/local/bin/supervisord -c /usr/local/etc/supervisord.conf
   25    24 12:00 ?        00:00:00 S     \_ /usr/local/sbin/syslogd -n -S -t -O -
   26    24 12:00 ?        00:00:00 S     \_ /usr/sbin/cron -f
   37    24 12:00 ?        00:00:00 S     \_ /bin/bash /usr/local/bin/valheim-updater
  303    37 12:05 ?        00:00:00 S     |   \_ sleep 9
   75    24 12:00 ?        00:00:00 S     \_ /bin/bash /usr/local/bin/valheim-backup
  301    75 12:05 ?        00:00:00 S     |   \_ sleep 20
  118    24 12:00 ?        00:00:00 S     \_ /bin/bash /usr/local/bin/valheim-server
  122   118 12:00 ?        00:01:01 Rl        \_ /opt/valheim/server/valheim_server.x86_64 -nographics -batchmode -name <redacted> -port 2456 -world <redacted> -public 0 -password <redacted>
  124   122 12:00 ?        00:00:00 S             \_ /bin/bash /usr/local/bin/valheim-server
  126   124 12:00 ?        00:00:00 Sl                \_ /usr/local/bin/valheim-logfilter -logtostderr -v 2
sh-5.1# /usr/local/bin/supervisorctl restart valheim-server
[stacktrace after interrupted]
sh-5.1# ps -eo pid,ppid,stime,tty,time,stat,cmd --forest
  PID  PPID STIME TT           TIME STAT CMD
  165     0 12:00 pts/0    00:00:00 Ss   /bin/sh
  376   165 12:08 pts/0    00:00:00 R+    \_ ps -eo pid,ppid,stime,tty,time,stat,cmd --forest
    1     0 12:00 ?        00:00:00 Ss   /usr/bin/tini -- /usr/local/bin/supervisord -c /usr/local/etc/supervisord.conf
   24     1 12:00 ?        00:00:04 S    /usr/bin/python3 /usr/local/bin/supervisord -c /usr/local/etc/supervisord.conf
   25    24 12:00 ?        00:00:00 S     \_ /usr/local/sbin/syslogd -n -S -t -O -
   26    24 12:00 ?        00:00:00 S     \_ /usr/sbin/cron -f
   37    24 12:00 ?        00:00:00 S     \_ /bin/bash /usr/local/bin/valheim-updater
  375    37 12:08 ?        00:00:00 S     |   \_ sleep 9
   75    24 12:00 ?        00:00:00 S     \_ /bin/bash /usr/local/bin/valheim-backup
  371    75 12:08 ?        00:00:00 S     |   \_ sleep 20
  118    24 12:00 ?        00:00:00 Z     \_ [valheim-server] <defunct>

After a restart attempt supervisord hangs and only a full container restart helps:

Mar 31 12:01:13 supervisord: valheim-server 03/31/2025 12:01:13: Game server connected
Mar 31 12:01:13 supervisord: valheim-server Unloading 2 unused Assets to reduce memory usage. Loaded Objects now: 199029.
Mar 31 12:01:13 supervisord: valheim-server Total: 146.667529 ms (FindLiveObjects: 14.659827 ms CreateObjectMapping: 31.757188 ms MarkObjects: 99.374035 ms  DeleteObjects: 0.875907 ms)
2025-03-31 12:05:35,543 INFO waiting for valheim-server to stop
Mar 31 12:05:35 supervisord: valheim-server DEBUG - [118] - Received signal to shut down valheim-server
Mar 31 12:05:35 supervisord: valheim-server INFO - Shutting down Valheim server with PID 122
Mar 31 12:05:35 supervisord: valheim-server DEBUG - [118] - Waiting for Valheim Server with PID 122 to shut down
Mar 31 12:05:35 supervisord: valheim-server 03/31/2025 12:05:35: Game - OnApplicationQuit
Mar 31 12:05:35 supervisord: valheim-server Am I Host? True
Mar 31 12:05:35 supervisord: valheim-server 03/31/2025 12:05:35: Available space to current user: 453242155008. Saving is blocked if below: 10699460 bytes. Warnings are given if below: 21398920
Mar 31 12:05:35 supervisord: valheim-server 03/31/2025 12:05:35: Shutting down
Mar 31 12:05:35 supervisord: valheim-server 03/31/2025 12:05:35: ZNet Shutdown
Mar 31 12:05:35 supervisord: valheim-server 03/31/2025 12:05:35: PrepareSave: clone done in 23ms
Mar 31 12:05:35 supervisord: valheim-server 03/31/2025 12:05:35: PrepareSave: ZDOExtraData.PrepareSave done in 47 ms
Mar 31 12:05:35 supervisord: valheim-server 03/31/2025 12:05:35: World save writing starting
Mar 31 12:05:35 supervisord: valheim-server 03/31/2025 12:05:35: World save writing started
Mar 31 12:05:36 supervisord: valheim-server 03/31/2025 12:05:36: Saved 67276 ZDOs
Mar 31 12:05:36 supervisord: valheim-server 03/31/2025 12:05:36: World save writing finishing
Mar 31 12:05:36 supervisord: valheim-server 03/31/2025 12:05:36: World save writing finished
Mar 31 12:05:36 supervisord: valheim-server 03/31/2025 12:05:36: World saved ( 501.16ms )
Mar 31 12:05:36 supervisord: valheim-server 03/31/2025 12:05:36: Considering autobackup. World time: 262.28, short time: 7200, long time: 43200, backup count: 4
Mar 31 12:05:36 supervisord: valheim-server 03/31/2025 12:05:36: Skipping backup. World session not long enough.
Mar 31 12:05:36 supervisord: valheim-server 03/31/2025 12:05:36: Unloading unused assets
Mar 31 12:05:36 supervisord: valheim-server Unloading 0 Unused Serialized files (Serialized files now loaded: 17)
Mar 31 12:05:36 supervisord: valheim-server 03/31/2025 12:05:36: Sending disconnect msg
Mar 31 12:05:36 supervisord: valheim-server ZPlayFabMatchmaking::UnregisterServer - unregistering server now. State: Uninitialized
Mar 31 12:05:36 supervisord: valheim-server 03/31/2025 12:05:36: Disposing socket
Mar 31 12:05:36 supervisord: valheim-server 03/31/2025 12:05:36: Stopping listening socket
Mar 31 12:05:36 supervisord: valheim-server 03/31/2025 12:05:36: Last socket, unregistering callback
Mar 31 12:05:36 supervisord: valheim-server 03/31/2025 12:05:36: ZSteamSocket  UnregisterGlobalCallbacks, existing sockets:0
Mar 31 12:05:36 supervisord: valheim-server 03/31/2025 12:05:36: Stopping build thread
2025-03-31 12:05:37,544 INFO waiting for valheim-server to stop
Mar 31 12:05:38 supervisord: valheim-server Unloading 1 unused Assets to reduce memory usage. Loaded Objects now: 199940.
Mar 31 12:05:38 supervisord: valheim-server Total: 157.813151 ms (FindLiveObjects: 13.772864 ms CreateObjectMapping: 23.257554 ms MarkObjects: 119.477589 ms  DeleteObjects: 1.304172 ms)
Mar 31 12:05:39 supervisord: valheim-server 03/31/2025 12:05:39: ZNet OnDestroy
Mar 31 12:05:39 supervisord: valheim-server 03/31/2025 12:05:39: Net scene destroyed
Mar 31 12:05:39 supervisord: valheim-server 03/31/2025 12:05:39: Steam manager on destroy
2025-03-31 12:05:39,544 INFO waiting for valheim-server to stop
Mar 31 12:05:39 supervisord: valheim-server Memory Statistics:
Mar 31 12:05:39 supervisord: valheim-server [ALLOC_TEMP_TLS] TLS Allocator
Mar 31 12:05:39 supervisord: valheim-server   StackAllocators :
Mar 31 12:05:39 supervisord: valheim-server     [ALLOC_TEMP_MAIN]
Mar 31 12:05:39 supervisord: valheim-server       Peak usage frame count: [0-1.0 KB]: 198402 frames, [1.0 KB-2.0 KB]: 9 frames, [2.0 KB-4.0 KB]: 13 frames, [4.0 KB-8.0 KB]: 7343 frames, [8.0 KB-16.0 KB]: 38 frames, [32.0 KB-64.0 KB]: 7 frames, [64.0 KB-128.0 KB]: 504 frames, [128.0 KB-256.0 KB]: 1 frames, [256.0 KB-0.5 MB]: 26 frames, [2.0 MB-4.0 MB]: 1 frames, [4.0 MB-8.0 MB]: 3 frames
Mar 31 12:05:39 supervisord: valheim-server       Initial Block Size 4.0 MB
Mar 31 12:05:39 supervisord: valheim-server       Current Block Size 7.7 MB
Mar 31 12:05:39 supervisord: valheim-server       Peak Allocated Bytes 7.7 MB
Mar 31 12:05:39 supervisord: valheim-server       Overflow Count 11
Mar 31 12:05:39 supervisord: valheim-server     [ALLOC_TEMP_Loading.AsyncRead]
Mar 31 12:05:39 supervisord: valheim-server       Initial Block Size 64.0 KB
Mar 31 12:05:39 supervisord: valheim-server       Current Block Size 128.0 KB
Mar 31 12:05:39 supervisord: valheim-server       Peak Allocated Bytes 127.8 KB
Mar 31 12:05:39 supervisord: valheim-server       Overflow Count 0
Mar 31 12:05:39 supervisord: valheim-server     [ALLOC_TEMP_Loading.PreloadManager]
Mar 31 12:05:39 supervisord: valheim-server       Initial Block Size 256.0 KB
Mar 31 12:05:39 supervisord: valheim-server       Current Block Size 0.5 MB
Mar 31 12:05:39 supervisord: valheim-server       Peak Allocated Bytes 384.2 KB
Mar 31 12:05:39 supervisord: valheim-server       Overflow Count 268160
Mar 31 12:05:39 supervisord: valheim-server     [ALLOC_TEMP_Background Job.Worker 8]
Mar 31 12:05:39 supervisord: valheim-server       Initial Block Size 32.0 KB
Mar 31 12:05:39 supervisord: valheim-server       Current Block Size 32.0 KB
Mar 31 12:05:39 supervisord: valheim-server       Peak Allocated Bytes 168 B
Mar 31 12:05:39 supervisord: valheim-server       Overflow Count 0
Mar 31 12:05:39 supervisord: valheim-server     [ALLOC_TEMP_Background Job.Worker 9]
Mar 31 12:05:39 supervisord: valheim-server       Initial Block Size 32.0 KB
Mar 31 12:05:39 supervisord: valheim-server       Current Block Size 32.0 KB
Mar 31 12:05:39 supervisord: valheim-server       Peak Allocated Bytes 0 B
Mar 31 12:05:39 supervisord: valheim-server       Overflow Count 0
Mar 31 12:05:39 supervisord: valheim-server     [ALLOC_TEMP_Job.Worker 0]
Mar 31 12:05:39 supervisord: valheim-server       Initial Block Size 256.0 KB
Mar 31 12:05:39 supervisord: valheim-server       Current Block Size 256.0 KB
Mar 31 12:05:39 supervisord: valheim-server       Peak Allocated Bytes 70.5 KB
Mar 31 12:05:39 supervisord: valheim-server       Overflow Count 0
Mar 31 12:05:39 supervisord: valheim-server     [ALLOC_TEMP_Background Job.Worker 10]
Mar 31 12:05:39 supervisord: valheim-server       Initial Block Size 32.0 KB
Mar 31 12:05:39 supervisord: valheim-server       Current Block Size 32.0 KB
Mar 31 12:05:39 supervisord: valheim-server       Peak Allocated Bytes 0 B
Mar 31 12:05:39 supervisord: valheim-server       Overflow Count 0
Mar 31 12:05:39 supervisord: valheim-server     [ALLOC_TEMP_Background Job.Worker 14]
Mar 31 12:05:39 supervisord: valheim-server       Initial Block Size 32.0 KB
Mar 31 12:05:39 supervisord: valheim-server       Current Block Size 32.0 KB
Mar 31 12:05:39 supervisord: valheim-server       Peak Allocated Bytes 0 B
Mar 31 12:05:39 supervisord: valheim-server       Overflow Count 0
Mar 31 12:05:39 supervisord: valheim-server     [ALLOC_TEMP_Background Job.Worker 6]
Mar 31 12:05:39 supervisord: valheim-server       Initial Block Size 32.0 KB
Mar 31 12:05:39 supervisord: valheim-server       Current Block Size 32.0 KB
Mar 31 12:05:39 supervisord: valheim-server       Peak Allocated Bytes 168 B
Mar 31 12:05:39 supervisord: valheim-server       Overflow Count 0
[supervisord hangs]

A possible workaround I've found is setting stopasgroup=true for valheim-server in the supervisord config. With that setting everything works as expected (though the logs about saving the world and cleanup up are missing).

sh-5.1# ps -eo pid,ppid,stime,tty,time,stat,cmd --forest
  PID  PPID STIME TT           TIME STAT CMD
  104     0 11:53 pts/0    00:00:00 Ss   /bin/sh
  287   104 11:57 pts/0    00:00:00 R+    \_ ps -eo pid,ppid,stime,tty,time,stat,cmd --forest
    1     0 11:53 ?        00:00:00 Ss   /usr/bin/tini -- /usr/local/bin/supervisord -c /usr/local/etc/supervisord.conf
   24     1 11:53 ?        00:00:00 S    /usr/bin/python3 /usr/local/bin/supervisord -c /usr/local/etc/supervisord.conf
   25    24 11:53 ?        00:00:00 S     \_ /usr/local/sbin/syslogd -n -S -t -O -
   26    24 11:53 ?        00:00:00 S     \_ /usr/sbin/cron -f
   37    24 11:53 ?        00:00:00 S     \_ /bin/bash /usr/local/bin/valheim-updater
  286    37 11:57 ?        00:00:00 S     |   \_ sleep 9
   75    24 11:53 ?        00:00:00 S     \_ /bin/bash /usr/local/bin/valheim-backup
  282    75 11:57 ?        00:00:00 S     |   \_ sleep 20
  127    24 11:53 ?        00:00:00 S     \_ /bin/bash /usr/local/bin/valheim-server
  131   127 11:53 ?        00:00:57 Sl        \_ /opt/valheim/server/valheim_server.x86_64 -nographics -batchmode -name <redacted> -port 2456 -world <redacted> -public 0 -password <redacted>
  132   131 11:53 ?        00:00:00 S             \_ /bin/bash /usr/local/bin/valheim-server
  135   132 11:53 ?        00:00:00 Sl                \_ /usr/local/bin/valheim-logfilter -logtostderr -v 2
sh-5.1# /usr/local/bin/supervisorctl restart valheim-server
valheim-server: stopped
valheim-server: started
sh-5.1# ps -eo pid,ppid,stime,tty,time,stat,cmd --forest
  PID  PPID STIME TT           TIME STAT CMD
  104     0 11:53 pts/0    00:00:00 Ss   /bin/sh
  397   104 11:58 pts/0    00:00:00 R+    \_ ps -eo pid,ppid,stime,tty,time,stat,cmd --forest
    1     0 11:53 ?        00:00:00 Ss   /usr/bin/tini -- /usr/local/bin/supervisord -c /usr/local/etc/supervisord.conf
   24     1 11:53 ?        00:00:06 S    /usr/bin/python3 /usr/local/bin/supervisord -c /usr/local/etc/supervisord.conf
   25    24 11:53 ?        00:00:00 S     \_ /usr/local/sbin/syslogd -n -S -t -O -
   26    24 11:53 ?        00:00:00 S     \_ /usr/sbin/cron -f
   37    24 11:53 ?        00:00:00 S     \_ /bin/bash /usr/local/bin/valheim-updater
  395    37 11:58 ?        00:00:00 S     |   \_ sleep 9
   75    24 11:53 ?        00:00:00 S     \_ /bin/bash /usr/local/bin/valheim-backup
  389    75 11:58 ?        00:00:00 S     |   \_ sleep 20
  303    24 11:58 ?        00:00:00 S     \_ /bin/bash /usr/local/bin/valheim-server
  307   303 11:58 ?        00:00:31 Sl        \_ /opt/valheim/server/valheim_server.x86_64 -nographics -batchmode -name <redacted> -port 2456 -world <redacted> -public 0 -password <redacted>
  309   307 11:58 ?        00:00:00 S             \_ /bin/bash /usr/local/bin/valheim-server
  311   309 11:58 ?        00:00:00 Sl                \_ /usr/local/bin/valheim-logfilter -logtostderr -v 2

Mar 31 11:54:08 supervisord: valheim-server 03/31/2025 11:54:08: Game server connected
Mar 31 11:54:08 supervisord: valheim-server Unloading 2 unused Assets to reduce memory usage. Loaded Objects now: 199029.
Mar 31 11:54:08 supervisord: valheim-server Total: 161.003263 ms (FindLiveObjects: 14.525029 ms CreateObjectMapping: 29.773318 ms MarkObjects: 115.879303 ms  DeleteObjects: 0.824887 ms)
2025-03-31 11:57:59,959 INFO waiting for valheim-server to stop
Mar 31 11:57:59 supervisord: valheim-server DEBUG - [127] - Received signal to shut down valheim-server
Mar 31 11:57:59 supervisord: valheim-server INFO - Shutting down Valheim server with PID 131
Mar 31 11:57:59 supervisord: valheim-server DEBUG - [127] - Waiting for Valheim Server with PID 131 to shut down
2025-03-31 11:58:01,960 INFO waiting for valheim-server to stop
2025-03-31 11:58:03,960 INFO waiting for valheim-server to stop
2025-03-31 11:58:05,960 INFO waiting for valheim-server to stop
Mar 31 11:58:05 supervisord: valheim-server DEBUG - [127] - Valheim server with PID 131 stopped
Mar 31 11:58:05 supervisord: valheim-server INFO - Releasing PID file /var/run/valheim/valheim-server.pid
Mar 31 11:58:05 supervisord: valheim-server INFO - Shutdown complete
2025-03-31 11:58:05,979 INFO stopped: valheim-server (exit status 0)
2025-03-31 11:58:05,983 INFO spawned: 'valheim-server' with pid 303
Mar 31 11:58:05 supervisord: valheim-server INFO - Running Valheim Server

As far as I understand this shouldn't be needed because supervisord only manages the valheim-server script and that will handle the "signal propagation". Maybe there's a bug in the script and it exits too early or something, but I did not check the script in detail.

theag3nt avatar Mar 31 '25 10:03 theag3nt

Also happening on my TrueNAS system. I'll give stopasgroup=true a shot, if it doesn't work then I might turn off the built in restart, and schedule a system cron job to just restart the docker instance every day... not sure if that works

huntyh avatar Jul 01 '25 07:07 huntyh