Sauberes Herunterfahren in Podman Setup benötigt expliziten Aufruf von --stop-signal=SIGTERM

[chris42]

Describe the issue you are experiencing

Nutzt man regulär podman stop <container> wird scheinbar SIGTERM nicht beachtet. Nach einem Timeout nutzt Podman dann SIGKILL. Dies führt natürlich zu einem "unclean shutdown".

Es ist kein zu früher Timeout. Ich habe diesen bereits auf 60 Sekunden erhöht (Ein Shutdown von der Oberfläche aus, braucht ungefähr 25 Sekunden). Die Logs zeigen auch keine Aktivität, wie sie sonst zum Shutdown zu beobachten ist.

SIGINT funktioniert, selbst wenn dies für Homematic scheinbar einen Reboot bedeutet:

[...]
systemd[1]: Stopping homematic.service - Rasberrymatic Homematic CCU...
podman/homematic[309725]: Rebooting container
[...]

Ganz kosmetisch ist dies auch nicht, da in Kombination mit rootful und priviligiertem Container /dev/watchdog scheinbar auf den Server durchschlägt, der sich bei SIGKILL dann - sofern man homematic nicht wieder startet - selbst resettet. (nice!)

Describe the behavior you expected

SIGTERM startet sauberen shutdown

Steps to reproduce the issue

Container starten per

podman run -d \
    --rm \
    --name homematic \
    --group-add keep-groups \
    --publish 80:80 \
    --publish 2000-2001:2000-2001 \
    --publish 2010:2010 \
    --publish 9292:9292 \
    --privileged=true \
    --stop-timeout 60 \
    --volume=/srv/var/local/homematic:/usr/local \
    --volume=/lib/modules:/lib/modules:ro \
    --volume=/run/udev/control:/run/udev/control \
    --label io.containers.autoupdate=registry \
    ghcr.io/jens-maus/raspberrymatic:latest

dann podman stop homematic nutzen.

Um ein anderes Signal für den Stop des Containers zu nutzen kann man einfach --stop-signal=SIGINT hinzufügen.

What is the version this bug report is based on?

3.75.6.20240316

Which base platform are you running?

oci_amd64 (Open Container Infrastructure, AMD64/x86_64)

Which HomeMatic/homematicIP radio module are you using?

HmIP-RFUSB

Anything in the logs that might be useful for us?

"Shutdown" Sequenz mit SIGINT:

Apr 16 20:40:28 diskstation systemd[1]: Stopping homematic.service - Rasberrymatic Homematic CCU...
Apr 16 20:40:28 diskstation podman/homematic[309725]: Rebooting container
Apr 16 20:40:29 diskstation podman/homematic[309725]: Setup onboard LEDs: shutdown, OK
Apr 16 20:40:29 diskstation podman/homematic[309725]: Stopping crond: OK
Apr 16 20:40:29 diskstation podman/homematic[309725]: Stopping Third-Party Addons: OK
Apr 16 20:40:36 diskstation podman/homematic[309725]: Stopping ReGaHss: ....OK
Apr 16 20:40:36 diskstation podman/homematic[309725]: Stopping HMIPServer: OK
Apr 16 20:40:36 diskstation podman/homematic[309725]: Stopping rfd: OK
Apr 16 20:40:36 diskstation kernel: eq3loop: eq3loop_close_slave() mmd_bidcos
Apr 16 20:40:36 diskstation podman/homematic[309725]: Stopping multimacd: OK
Apr 16 20:40:36 diskstation kernel: eq3loop: eq3loop_close_master() mmd_bidcos
Apr 16 20:40:36 diskstation kernel: eq3loop: eq3loop_close_master() mmd_bidcos destroy device
Apr 16 20:40:36 diskstation kernel: eq3loop: eq3loop_close_master() mmd_hmip
Apr 16 20:40:36 diskstation kernel: eq3loop: eq3loop_close_slave() mmd_hmip
Apr 16 20:40:36 diskstation kernel: eq3loop: eq3loop_close_slave() mmd_hmip destroy device
Apr 16 20:40:38 diskstation podman/homematic[309725]: Stopping hs485d: OK
Apr 16 20:40:38 diskstation podman/homematic[309725]: Stopping NUT services: OK
Apr 16 20:40:38 diskstation podman/homematic[309725]: Stopping sshd: OK
Apr 16 20:40:38 diskstation podman/homematic[309725]: Stopping ssdpd: OK
Apr 16 20:40:38 diskstation podman/homematic[309725]: Shutting down ser2net: OK
Apr 16 20:40:38 diskstation podman/homematic[309725]: Stopping lighttpd: OK
Apr 16 20:40:38 diskstation podman/homematic[309725]: Stopping eq3configd: OK
Apr 16 20:40:38 diskstation podman/homematic[309725]: Stopping xinetd: OK
Apr 16 20:40:45 diskstation kernel: podman0: port 1(veth0) entered disabled state
Apr 16 20:40:45 diskstation podman/homematic[309725]: Stopping network: eth0: link down, OK
Apr 16 20:40:45 diskstation podman/homematic[309725]: Stopping iptables: OK
Apr 16 20:40:45 diskstation podman/homematic[309725]: Stopping logging: OK
Apr 16 20:40:45 diskstation podman/homematic[309725]: Cleaning up System: OK
Apr 16 20:40:45 diskstation podman/homematic[309725]: Running seedrng: OK
Apr 16 20:40:45 diskstation podman/homematic[309725]: Cleaning up RTC Clock: OK
Apr 16 20:40:45 diskstation podman/homematic[309725]: [31B blob data]
Apr 16 20:40:45 diskstation podman/homematic[309725]: [31B blob data]
Apr 16 20:40:46 diskstation podman/homematic[309725]: [31B blob data]
Apr 16 20:40:46 diskstation podman/homematic[309725]: [26B blob data]
Apr 16 20:40:47 diskstation podman[334986]: 2024-04-16 20:40:47.776028945 +0200 CEST m=+19.247356673 container died a8417ac318a9bf6a13e922a478b4b4c12510e27ae787cf3c4e2c5f4a19ae3cc6 (image=ghcr.io/jens-maus/raspberrymatic:latest, name=homematic, org.opencontainers.image.ref.name=master, org.opencontainers.image.vendor=RasperryMatic OpenSource Project, io.containers.autoupdate=registry, io.hass.arch=armv7|aarch64|amd64, org.opencontainers.image.url=https://raspberrymatic.de, org.opencontainers.image.description=Alternative OS for your HomeMatic CCU, org.opencontainers.image.revision=6d18e07d981aae9429466252f4ff96fb2ba60e9c, org.opencontainers.image.title=RaspberryMatic, PODMAN_SYSTEMD_UNIT=homematic.service, org.opencontainers.image.created=2024-03-16 14:39:23, io.hass.description=HomeMatic/homematicIP CCU central based on RaspberryMatic, io.hass.type=addon, org.opencontainers.image.authors=RaspberryMatic OpenSource Team, org.opencontainers.image.documentation=https://github.com/jens-maus/RaspberryMatic/wiki, io.hass.url=https://github.com/jens-maus/RaspberryMatic/tree/master/home-assistant-addon, org.opencontainers.image.version=3.75.6.20240316, org.opencontainers.image.source=https://github.com/jens-maus/RaspberryMatic, io.hass.name=RaspberryMatic CCU, io.hass.version=3.75.6.20240316, org.opencontainers.image.licenses=Apache-2.0)
Apr 16 20:40:47 diskstation kernel: podman0: port 1(veth0) entered disabled state
Apr 16 20:40:47 diskstation kernel: device veth0 left promiscuous mode
Apr 16 20:40:47 diskstation kernel: podman0: port 1(veth0) entered disabled state
Apr 16 20:40:48 diskstation systemd[1]: run-netns-netns\x2d3b02a94c\x2d47e5\x2db2a9\x2d3208\x2df1b6c62e8e5a.mount: Deactivated successfully.
Apr 16 20:40:48 diskstation systemd[1]: var-lib-containers-storage-overlay\x2dcontainers-a8417ac318a9bf6a13e922a478b4b4c12510e27ae787cf3c4e2c5f4a19ae3cc6-userdata-shm.mount: Deactivated successfully.
Apr 16 20:40:48 diskstation systemd[1]: var-lib-containers-storage-overlay-7161f85d314378b915a277a2b48b6312dfb032b9185be7cc895ce5c7096528ee-merged.mount: Deactivated successfully.
Apr 16 20:40:48 diskstation podman[334986]: 2024-04-16 20:40:48.734438835 +0200 CEST m=+20.205766573 container remove a8417ac318a9bf6a13e922a478b4b4c12510e27ae787cf3c4e2c5f4a19ae3cc6 (image=ghcr.io/jens-maus/raspberrymatic:latest, name=homematic, org.opencontainers.image.source=https://github.com/jens-maus/RaspberryMatic, org.opencontainers.image.licenses=Apache-2.0, org.opencontainers.image.version=3.75.6.20240316, io.hass.type=addon, io.hass.description=HomeMatic/homematicIP CCU central based on RaspberryMatic, org.opencontainers.image.url=https://raspberrymatic.de, org.opencontainers.image.documentation=https://github.com/jens-maus/RaspberryMatic/wiki, org.opencontainers.image.revision=6d18e07d981aae9429466252f4ff96fb2ba60e9c, org.opencontainers.image.title=RaspberryMatic, org.opencontainers.image.vendor=RasperryMatic OpenSource Project, io.containers.autoupdate=registry, org.opencontainers.image.ref.name=master, io.hass.arch=armv7|aarch64|amd64, org.opencontainers.image.authors=RaspberryMatic OpenSource Team, io.hass.name=RaspberryMatic CCU, PODMAN_SYSTEMD_UNIT=homematic.service, org.opencontainers.image.created=2024-03-16 14:39:23, org.opencontainers.image.description=Alternative OS for your HomeMatic CCU, io.hass.url=https://github.com/jens-maus/RaspberryMatic/tree/master/home-assistant-addon, io.hass.version=3.75.6.20240316)
Apr 16 20:40:48 diskstation homematic[334986]: a8417ac318a9bf6a13e922a478b4b4c12510e27ae787cf3c4e2c5f4a19ae3cc6
Apr 16 20:40:48 diskstation systemd[1]: homematic.service: Main process exited, code=exited, status=129/n/a
Apr 16 20:40:48 diskstation systemd[1]: homematic.service: Failed with result 'exit-code'.
Apr 16 20:40:48 diskstation systemd[1]: Stopped homematic.service - Rasberrymatic Homematic CCU.
Apr 16 20:40:48 diskstation systemd[1]: homematic.service: Consumed 17.826s CPU time.
Apr 16 20:40:49 diskstation systemd[1]: var-lib-containers-storage-overlay.mount: Deactivated successfully.

Additional information

No response

[jens-maus]

Ok, das Problem mit dem WatchDog habe ich denke ich mal nun behoben in dem sich ein RaspberryMatic Docker/LXC Container nun wirklich nicht mehr um einen host watchdog kümmern sollte. Danke für diesen Hinweis.

Bzgl. stop signal, so habe ich das hier gerade mal mit docker stop <name> probiert sowie auch mit docker stop --signal SIGTERM <name> und in beiden fällen fährt der Container ohne Probleme herunter.

[chris42]

Scheinbar ist dann ein Unterschied wie Docker und Podman die Container handhabt. Das Problem hat mit Docker früher nicht bestanden - oder zumindest ist es mir nicht aufgefallen.
In Kombination mit dem SIGINT lässt es mich vermuten, dass ggf. Punkt 3 hier trifft? https://hynek.me/articles/docker-signals/
Was Docker dann allerdings anders macht bleibt noch fraglich - evtl. schicken die immer beides?

[jens-maus]

Danke für die weiteren Infos. Nun hab ich mir das mal selbst angeschaut und versucht dein beschriebenes Verhalten auch via podman nachzuvollziehen. In der Tat kann ich das reproduzieren, d.h. wenn ich podman stop mache beendet sich der Container nicht sofort aber wird dann nach dem timeout hart via SIGKILL einfach abgeschossen. Siehe:

:~$ podman stop homematic
^[[OWARN[0060] StopSignal  failed to stop container homematic in 60 seconds, resorting to SIGKILL 
homematic

Das lässt sich aber via docker nicht nachvollziehen. Dort wird der Container immer sauber beendet wenn man docker stop macht.

Interessant wird es jedoch wenn man in podman den container explizit mit der Option --stop-signal SIGTERM startet. Das sollte ja eigentlich default sein laut dokumentation:

   --stop-signal=signal
       Signal to stop a container. Default is SIGTERM.

Wenn man die Option nun aber explizit angibt beim podman run dann funktioniert auch das beenden des Containers via podman stop.

Dann hab ich mir mal im laufenden container angeschaut welches stopsignal aktiv ist für den laufenden container:

:~$ podman container inspect homematic | grep -i stop
                    "org.opencontainers.image.stopSignal": "37",
               "StopSignal": 37,
                    "--stop-timeout=60",
               "StopTimeout": 60,

Wie man sehen kann ist hierbei das aktiveStopSignal 37 welches keinem gängigen stop signal entspricht. Keine Ahnung woher podman das nimmt das er das auf 37 setzt?!?

Startet man nun jedoch podman run mit der --stop-signal=SIGTERM option kommt folgendes heraus:

:~$ podman container inspect homematic | grep -i stop
                    "org.opencontainers.image.stopSignal": "15",
               "StopSignal": 15,
                    "--stop-signal=SIGTERM",
                    "--stop-timeout=60",
               "StopTimeout": 60,

Und hier kommt dann 15 raus was wiederrum SIGTERM entspricht und damit fährt der container dann wie in docker korrekt herunter.

Versuche ich das selbe via Docker zu reproduzieren gibt das inspect ohne explizite angabe von --stop-signal folgendes aus:

$ docker container inspect homematic | grep -i stop
            "StopTimeout": 60

D.h. es gibt da keine explizite Angabe von StopSignal. Und wenn ich dann explizit --stop-signal=SIGTERM angebe sieht das ganze so aus:

$ docker container inspect homematic | grep -i stop
            "StopSignal": "SIGTERM",
            "StopTimeout": 60

Hier scheinen sich also podman und docker wohl irgendwie zu unterscheiden. Und warum bei podman immer automatisch das stopsignal auf 37 (????) gesetzt wird ist mir auch noch nicht klar.

Ich würde daher vorschlagen du gibst einfach erst einmal explizit --stop-signal=SIGTERM beim starten des Containers zusätzlich zum --stop-timeout an, dann sollte sich alles sauber beenden. Ich werde abgesehen davon dann mal probieren ob das angeben des STOPSIGNAL im Dockerfile bzw. das explizite benennen von org.opencontainers.image.stopSignal irgendeine verbesserung bringt bzw. podman diese Option dann vielleicht irgendwie zum anlass nimmt mit dem richtigen stop signal zu arbeiten.

[chris42]

Danke für das Reproduzieren. Das ist tatsächlich sehr merkwürdig. Ich habe noch andere Podman Container laufen, bei denen das Signal ohne Angabe in der Kommandozeile richtig gesetzt ist. Einziger Unterschied ist, dass homematic ein rootful container ist.
Werde den Titel als Referenz für andere anpassen und das Signal erst mal manuell setzen. Wenn ich noch etwas testen soll, gib gerne Bescheid.

[jens-maus]

So, hab nun mal explizit STOPSIGNAL SIGTERM im Dockerfile angegeben (siehe dcacd98) und nun wird das stop signal korrekt auf 15 (SIGTERM) gesetzt, auch wenn das eigentlich ja der Default sein sollte. D.h. nun sollte mit dem nächste nightly snapshot der container auch mit einem podman stop korrekt herunterfahren auch wenn man nicht explizit --stop-signal=SIGTERM beim starten angegeben hat. Und das Problem mit dem watchdog und dem herunterfahren des hosts selber sollte auch nicht mehr passieren.