TEST-56-EXIT-TYPE hags in nspawn when run on a host using legacy cgroups

[mrc0mmand]

systemd version the issue has been seen with

v250.3 (stable)

Used distribution

RHEL 9

Linux kernel version used (uname -a)

5.14.0-47.el9.x86_64

First of all, I'm not sure if ExitType=cgroup is supposed to work under legacy cgroups (but the test's QEMU part works fine even with legacy cgroups), so I'm a bit puzzled.

Currently the test hangs and eventually timeouts when running the nspawn part on a host with legacy cgroups (systemd.unified_cgroup_hierarchy=0 systemd.legacy_systemd_cgroup_controller=1):

[ 1797.954362] H test56-exit-cgroup-parentless.sh[79]: + systemctl kill --signal 9 six
[ 1797.957963] H systemd[1]: Bus private-bus-connection: changing state UNSET → OPENING
[ 1797.958261] H systemd[1]: sd-bus: starting bus private-bus-connection on fds 38/38 (socket:[284205], socket:[284205])...
[ 1797.958366] H systemd[1]: Bus private-bus-connection: changing state OPENING → AUTHENTICATING
[ 1797.958448] H systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1 iface=org.freedesktop.systemd1.Manager
[ 1797.958790] H systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/job iface=org.freedesktop.systemd1.Job
[ 1797.958916] H systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/unit iface=org.freedesktop.systemd1.Unit
[ 1797.959388] H systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/unit iface=org.freedesktop.systemd1.Automount
[ 1797.959499] H systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/unit iface=org.freedesktop.systemd1.Device
[ 1797.959590] H systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/unit iface=org.freedesktop.systemd1.Mount
[ 1797.960331] H systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/unit iface=org.freedesktop.systemd1.Path
[ 1797.960445] H systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/unit iface=org.freedesktop.systemd1.Scope
[ 1797.960527] H systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/unit iface=org.freedesktop.systemd1.Service
[ 1797.961971] H systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/unit iface=org.freedesktop.systemd1.Slice
[ 1797.962080] H systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/unit iface=org.freedesktop.systemd1.Socket
[ 1797.962568] H systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/unit iface=org.freedesktop.systemd1.Swap
[ 1797.963059] H systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/unit iface=org.freedesktop.systemd1.Target
[ 1797.963173] H systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/unit iface=org.freedesktop.systemd1.Timer
[ 1797.964932] H systemd[1]: Registering bus object implementation for path=/org/freedesktop/LogControl1 iface=org.freedesktop.LogControl1
[ 1797.965045] H systemd[1]: Accepted new private connection.
[ 1797.965130] H systemd[1]: Bus private-bus-connection: changing state AUTHENTICATING → RUNNING
[ 1797.965223] H systemd[1]: Got message type=method_call sender=n/a destination=org.freedesktop.systemd1 path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=KillUnit cookie=1 reply_cookie=0 signature=ssi erro>
[ 1797.965323] H systemd[1]: six.service: Sending signal SIGKILL to process 75 (sleep) on client request.
[ 1797.965473] H systemd[1]: six.service: Sending signal SIGKILL to process 76 (bash) on client request.
[ 1797.965608] H systemd[1]: six.service: Sending signal SIGKILL to process 77 (sleep) on client request.
[ 1797.965740] H systemd[1]: six.service: Sending signal SIGKILL to process 79 (bash) on client request.
[ 1797.965940] H systemd[1]: six.service: Sending signal SIGKILL to process 81 (systemctl) on client request.
[ 1797.966099] H systemd[1]: Sent message type=method_return sender=org.freedesktop.systemd1 destination=n/a path=n/a interface=n/a member=n/a cookie=1 reply_cookie=1 signature=n/a error-name=n/a error-message=n/a
[ 1797.966245] H systemd[1]: Received SIGCHLD from PID 75 (sleep).
[ 1797.966387] H systemd[1]: Child 75 (sleep) died (code=killed, status=9/KILL)
[ 1797.966530] H systemd[1]: Child 76 (bash) died (code=killed, status=9/KILL)
[ 1797.966670] H systemd[1]: Child 79 (bash) died (code=killed, status=9/KILL)
[ 1797.966809] H systemd[1]: Child 77 (sleep) died (code=killed, status=9/KILL)
[ 1797.966975] H systemd[1]: Child 81 (systemctl) died (code=killed, status=9/KILL)
[ 1797.967110] H systemd[1]: Received SIGCHLD from PID 81 (n/a).
[ 1797.967244] H systemd[1]: systemd-journald.service: Received EPOLLHUP on stored fd 37 (stored), closing.
[ 1797.967386] H systemd[1]: Bus private-bus-connection: changing state RUNNING → CLOSING
[ 1797.967519] H systemd[1]: Bus private-bus-connection: changing state CLOSING → CLOSED
[ 1797.967647] H systemd[1]: Got disconnect on private connection.
[ 1800.712238] H systemd[29]: KDSETMODE ioctl for switching to text mode failed on TTY, ignoring: Inappropriate ioctl for device
[ 1800.716127] H systemd[29]: Not writing wtmp: No such file or directory
[ 1800.716273] H systemd[29]: console-getty.service: Kernel keyring access prohibited, ignoring.
[ 1800.716579] H systemd[29]: console-getty.service: Executing: /sbin/agetty -o "-p -- \\u" --noclear --keep-baud - 115200,38400,9600 vt220
[ 1905.746766] H systemd[1]: systemd-journald.service: Got notification message from PID 17 (WATCHDOG=1)
[ 1905.911468] H systemd[1]: systemd-logind.service: Got notification message from PID 25 (WATCHDOG=1)
[ 2014.389409] H systemd[1]: systemd-journald.service: Got notification message from PID 17 (WATCHDOG=1)
[ 2025.911479] H systemd[1]: systemd-logind.service: Got notification message from PID 25 (WATCHDOG=1)
[ 2085.746801] H systemd[1]: systemd-journald.service: Got notification message from PID 17 (WATCHDOG=1)
[ 2145.911556] H systemd[1]: systemd-logind.service: Got notification message from PID 25 (WATCHDOG=1)
[ 2178.381364] H systemd[1]: systemd-journald.service: Got notification message from PID 17 (WATCHDOG=1)
[ 2265.746841] H systemd[1]: systemd-journald.service: Got notification message from PID 17 (WATCHDOG=1)
[ 2265.911521] H systemd[1]: systemd-logind.service: Got notification message from PID 25 (WATCHDOG=1)
[ 2375.746803] H systemd[1]: systemd-journald.service: Got notification message from PID 17 (WATCHDOG=1)
[ 2385.911513] H systemd[1]: systemd-logind.service: Got notification message from PID 25 (WATCHDOG=1)
...
H login: Trying to halt container. Send SIGTERM again to trigger immediate termination.
Container TEST-56-EXIT-TYPE terminated by signal KILL.

E: Test timed out after 600s

Console log: https://jenkins-systemd.apps.ocp.ci.centos.org/job/rhel9-centos9/101/artifact//systemd-centos-ci/artifacts_all/artifacts_rq34fbbk/testsuite-logs-legacy-rhel9.Eam/TEST-56-EXIT-TYPE_FAIL.log
Journal: https://jenkins-systemd.apps.ocp.ci.centos.org/job/rhel9-centos9/101/artifact//systemd-centos-ci/artifacts_all/artifacts_rq34fbbk/testsuite-logs-legacy-rhel9.Eam/TEST-56-EXIT-TYPE/system.journal

The journal contains both runs (-b -1 is the successful QEMU run, -b is the failing nspawn one).

/cc @unusual-thoughts

[poettering]

cgroup empty notifications are unfortunately not reliable in containers on cgroupsv1...

[mrc0mmand]

cgroup empty notifications are unfortunately not reliable in containers on cgroupsv1...

I suspected something like that, just wanted to make sure. I don't really care about ExitType=cgroup on cgroupsv1, so just documenting the behavior in the man page would be enough for me (if it's worth documenting at all). Not sure if there's anything we could do to make it work reliably.

[bluca]

Can we detect v1 in the test and skip?

[poettering]

yeah, we should.

i mean, at this point, cgroupsv1 is legacy enough for me not caring if all features work with it really.

[bluca]

That's fair, but I also think we should refuse this setting and error out when starting the unit - it's easy enough to detect and in fact we already do it in several places

[mrc0mmand]

yeah, we should.

i mean, at this point, cgroupsv1 is legacy enough for me not caring if all features work with it really.

Agreed, I'll prep a patch for the test.