What is the normal shutdown scenario for rootless containers managed by systemd user?

[graelo]

Hi,

I'm on Debian testing, with podman 4.3.1 (with crun, so I use cgroup v2). I have a few (<5) rootless containers owned by my user (linger enabled). The containers start without issues, but during shutdown I always experience the well-known 2 min delay during shutdown. After that delay, the shutdown proceeds.

• In the console, during shutdown or reboot, the User Manager (I guess this is dbus-org.freedesktop.login1.service) begins stopping earlier than any podman service -> and then later, I see the message "A stop job is running for User Manager for UID xxxx"
• looking at the journal on the next boot, I see that during the delay, podman tries to stop the containers, but this requires access to dbus, and dbus being shutdown, it refuses to answer. At least that's my understanding. If I stop my container units prior to shutdown/reboot, then I experience no delay.

For instance, here are some of those messages

Jan 12 10:23:23 nas dbus-daemon[1316]: [system] Activating via systemd: service name='org.freedesktop.login1' unit='dbus-org.freedesktop.login1.service' requested by ':1.3024' (uid=1000 pid=3676763 comm="/usr/bin/podman container stop --ignore -t 10 --ci")
Jan 12 10:23:23 nas dbus-daemon[1316]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.login1.service': Refusing activation, D-Bus is shutting down.

FYI, I've tried with my units being of Type=notify with NotifyAccess=all, and also with Type=forking. I use the standard template from podman generate systemd ..., and I've modified it a bit, but my understanding is that the problem is elsewhere.

I've also tried to put the user dbus.service in the root slice (it's in the session.slice by default) by overriding the unit, but this had no effect.

I'd like to know where my understanding is flawed and how this is supposed to work, so that I can try fixing this issue.

Thanks a ton!

Some details

podman info

host:
  arch: amd64
  buildahVersion: 1.28.0
  cgroupControllers:
  - cpu
  - memory
  - pids
  cgroupManager: systemd
  cgroupVersion: v2
  conmon:
    package: conmon_2.1.3+ds1-1_amd64
    path: /usr/bin/conmon
    version: 'conmon version 2.1.3, commit: unknown'
  cpuUtilization:
    idlePercent: 99.33
    systemPercent: 0.4
    userPercent: 0.26
  cpus: 8
  distribution:
    codename: bookworm
    distribution: debian
    version: unknown
  eventLogger: journald
  hostname: nas
  idMappings:
    gidmap:
    - container_id: 0
      host_id: 1000
      size: 1
    - container_id: 1
      host_id: 624288
      size: 65536
    uidmap:
    - container_id: 0
      host_id: 1000
      size: 1
    - container_id: 1
      host_id: 624288
      size: 65536
  kernel: 6.0.0-6-amd64
  linkmode: dynamic
  logDriver: journald
  memFree: 21965787136
  memTotal: 33435021312
  networkBackend: netavark
  ociRuntime:
    name: crun
    package: crun_1.5+dfsg-1+b1_amd64
    path: /usr/bin/crun
    version: |-
      crun version 1.5
      commit: 54ebb8ca8bf7e6ddae2eb919f5b82d1d96863dea
      spec: 1.0.0
      +SYSTEMD +SELINUX +APPARMOR +CAP +SECCOMP +EBPF +YAJL
  os: linux
  remoteSocket:
    exists: true
    path: /run/user/1000/podman/podman.sock
  security:
    apparmorEnabled: false
    capabilities: CAP_CHOWN,CAP_DAC_OVERRIDE,CAP_FOWNER,CAP_FSETID,CAP_KILL,CAP_NET_BIND_SERVICE,CAP_SETFCAP,CAP_SETGID,CAP_SETPCAP,CAP_SETUID,CAP_SYS_CHROOT
    rootless: true
    seccompEnabled: true
    seccompProfilePath: /usr/share/containers/seccomp.json
    selinuxEnabled: false
  serviceIsRemote: false
  slirp4netns:
    executable: /usr/bin/slirp4netns
    package: slirp4netns_1.2.0-1_amd64
    version: |-
      slirp4netns version 1.2.0
      commit: 656041d45cfca7a4176f6b7eed9e4fe6c11e8383
      libslirp: 4.7.0
      SLIRP_CONFIG_VERSION_MAX: 4
      libseccomp: 2.5.4
  swapFree: 4898942976
  swapTotal: 4898942976
  uptime: 9h 27m 11.00s (Approximately 0.38 days)
plugins:
  authorization: null
  log:
  - k8s-file
  - none
  - passthrough
  - journald
  network:
  - bridge
  - macvlan
  volume:
  - local
registries: {}
store:
  configFile: /home/graelo/.config/containers/storage.conf
  containerStore:
    number: 4
    paused: 0
    running: 4
    stopped: 0
  graphDriverName: overlay
  graphOptions: {}
  graphRoot: /home/graelo/.local/share/containers/storage
  graphRootAllocated: 112874229760
  graphRootUsed: 24373370880
  graphStatus:
    Backing Filesystem: extfs
    Native Overlay Diff: "true"
    Supports d_type: "true"
    Using metacopy: "false"
  imageCopyTmpDir: /tmp/graelo
  imageStore:
    number: 4
  runRoot: /run/user/1000/containers
  volumePath: /home/graelo/.local/share/containers/storage/volumes
version:
  APIVersion: 4.3.1
  Built: 0
  BuiltTime: Thu Jan  1 01:00:00 1970
  GitCommit: ""
  GoVersion: go1.19.4
  Os: linux
  OsArch: linux/amd64
  Version: 4.3.1

One example Unit

[Unit]
Description=Podman container-home-assistant.service

Wants=network-online.target
After=network-online.target
RequiresMountsFor=/tank/containers/home-assistant
RequiresMountsFor=%t/containers

[Service]
Environment=PODMAN_SYSTEMD_UNIT=%n
Restart=on-failure
TimeoutStopSec=70
PIDFile=%t/%N.pid
Type=notify
NotifyAccess=all

ExecStartPre=/bin/rm -f %t/%N.pid %t/%N.ctr-id
ExecStart=/usr/bin/podman container run \
          --conmon-pidfile=%t/%N.pid \
          --cidfile=%t/%N.ctr-id \
          --cgroups=no-conmon \
          --userns=keep-id \
          --sdnotify=conmon \
          --replace \
          --detach \
          --volume /etc/timezone:/etc/timezone:ro \
          --volume /etc/localtime:/etc/localtime:ro \
          --volume /tank/containers/home-assistant/config:/config:Z,U \
          --network host \
          # --publish 127.0.0.1:9001:9001 \
          # --publish 127.0.0.1:51827:51827 \
          --label="io.containers.autoupdate=registry" \
          --name home-assistant \
          docker.io/homeassistant/home-assistant:stable

ExecStop=/usr/bin/podman container stop \
          --ignore -t 10 \
          --cidfile=%t/%N.ctr-id

ExecStopPost=/usr/bin/podman container rm \
          -f \
          --ignore -t 10 \
          --cidfile=%t/%N.ctr-id

[Install]
WantedBy=default.target

[vrothberg]

Thanks for reaching out.

Does the issue occur on non-edited files (i.e., exactly what generate systemd creates)? A general note: edited units are not supported upstream, only the exact output of generate systemd.

There is a bug in 4.3.1 in combination with health checks (fixed by #16785) but your contianer doesn't seem to use health checks (neither the image).

[graelo]

Hi Valentin, thanks.

Using the generated unit (using --new) my problem disappears 🥰. The only differences that I can spot are the pid file and %N vs %n. I'm super happy, thanks.

[graelo]

Well, I spoke too soon ;) The waiting time had shortened indeed, but it's merely because I had tested with just one container; as soon as I add others, the problem still exists.

Anyway, I don't think this is a podman issue: it's simply due to how things should work for systemd user services. Here is my understanding:

Podman config contains

Wants=network-online.target
After=network-online.target

but for user services (managed by systemctl --user) this network-online.target does not exist by default.

Sure, you can copy the network-online.target unit into your user, or systemctl --user link /lib/systemd/system/network-online.target ..., but this will run a user version of the system's network-online.target, not the system one. Such a user target will ensure that the user unit is started effectively after the user network-online.target has been reached, but this won't change the fact that the system dbus will be shutdown independently of your user container.

The reason is given in the systemd docs: a user service/target cannot depend on system services/targets: in particular in the case of shutdown, system shutdown should not blocked by some user service.

That makes sense to me, it's a bit unfortunate, but here's what you get for running user services ;)

Cheers and thanks for the support anyway!

[rhatdan]

Somewhere else there was a suggestion that the Wants, and After targets be changed to default.target.
I have no idea if this fixes the problem.

[graelo]

Thanks, I will try that.

[graelo]

If that's easy for you, could you describe how these differences explain the different behavior? I'm just curious. Otherwise, I'll dig into the docs and try identify what triggers the chicken & egg scenario I had.

[vrothberg]

I wish it was that easy for me :^)

The difference between %N and %n is that %N will remove the type suffix. I am unable to explain/imagine why that would make the difference.

But I am glad that it's working. I think that's a nice example on why we only support the exact output generate systemd. Even small changes to the generated unit files can have big (negative) impacts.

[graelo]

Indeed! (yes, I expected the suffix to not be the issue)

Thanks again!

[rhatdan]

Also why we need to move to quadlet...

[vrothberg]

That really depends. Quadlet doesn't protect from users setting/overriding certain aspects of a unit file that could break running Podman either. Imagine changing the Type and setting the pid file to something else.

[projectgus]

FWIW, I see exactly the same symptoms on debian bookworm, podman 4.3.1, cgroups v2 with crun, and systemd user services. Not expecting any action from upstream but I thought I'd note some things for anyone else experiencing the same.

I'm using units generated for pods as podman generate systemd --new -f -n PODNAME and otherwise unmodified, although I have one container not in a pod which seems to have the same issue.

Behaviour is that system shutdown sometimes hangs indefinitely, or more often hangs for an extended period until a lot of podman processes are sent SIGKILL by systemd.

The extended hang (although not 100% same behaviour) can be triggered with systemctl stop user-<UID>.service to save on reboots.

---

On shutdown, the error Activation via systemd failed for unit 'dbus-org.freedesktop.login1.service': Refusing activation, D-Bus is shutting down. message from the first post seems to be because podman tries to activate this dbus service which is provided by systemd-logind, a system service that might already have stopped during a shutdown. This can be prevented at the system level by adding a dependency from all user sessions to systemd-logind:

# cat /etc/systemd/system/[email protected]/keep_logind.conf 
[Unit]
After=systemd-logind.service

(Recommend also adding rsyslog.service here as well, otherwise a lot of user session logs during shutdown end up being dropped.)

I don't know if this dependency breaks anything else, but seems unlikely as this is a race condition otherwise (systemd-logind will exit on shutdown, could happen before or after any user sessions.)

---

This by itself wasn't enough to fix the observed behaviour. What seems to happen is something like:

1. Systemd executes ExecStop=podman stop --ignore -t 10 --cidfile=%t/%n.ctr-id for each container.
2. Containers begin to stop, and logs almost immediately show lines from podman saying container died [container id] [container details] for each container.
3. Some containers' systemd services stop as expected at this point, and everything is good.
4. For other containers, the podman stop process doesn't exit and appears to hang (although podman has already logged that this container has "died"). This feels like a race condition with something else being cleaned up in the system. Although it may be that these containers have some common property that I don't see (it doesn't seem to be health checks).
5. After some time, it seems systemd also launches ExecStopPost=/usr/bin/podman rm -f --ignore -t 10 --cidfile=%t/%n.ctr-id
6. This podman rm process also hangs in many cases.
7. Meanwhile, systemd is counting away with User job container-<NAME>.service/stop running (30s / 1min 10s)...)
8. Eventually the systemd timeout expires and all of these hanging podman stop and podman rm processes are sent SIGKILL by [email protected]. Shutdown (usually) completes after this.

Note that the containers seem to have exited fine at step (3), from what I can tell. The problem seems to be that the hanging ExecStop and ExecStopPost processes prevent systemd from actually marking the service as stopped. I don't know what they're hanging on.

I've experimented with tips in this discussion, such as changing the dependency to default.target. This doesn't seem to change this overall pattern (it did seem like it might have worked around the occasional indefinite hangs in shutdown, though!) So have persisted this as:

$ cat ~/.config/systemd/user/container-.service.d/after_default.conf 
[Unit]
After=default.target

$ cat ~/.config/systemd/user/pod-.service.d/after_default.conf 
[Unit]
After=default.target

I also tried setting the libpod scope KillMode to none as it does seem like the scope is cleaned up very early and I thought maybe something in crun is blocking on something that no longer exists here. However this didn't seem to change anything.

To reiterate, absolutely don't expect any action or response from upstream about this very vague account of behaviour in an old version. However, I thought this might be halfway useful for someone who has run into the same thing.

[projectgus]

Updated to debian trixie with podman 4.9.2. Adding the system-level dependency on systemd-logind.service seems necessary (maybe this isn't a red herring and podman stop and podman rm were failing outright if they couldn't contact it). Otherwise container services seem to stop properly as expected, now!

[graelo]

Thanks @projectgus. I'll look into it when I have time, but it's great to know you have a clean solution to this!