Comment 10 for bug 2063094

Revision history for this message
Adrien Nader (adrien) wrote :

Attaching 20 seconds of strace output for my case.

This actually lead me to look at /var/log/unattended-upgrades/unattended-upgrades-shutdown.log and I Noticed the following:

2024-01-18 15:01:16,996 WARNING - SIGTERM or SIGHUP received, stopping unattended-upgrades only if it is running
2024-01-18 15:01:22,365 WARNING - Could not get delay inhibitor lock
2024-01-18 15:01:24,367 WARNING - Unable to monitor PrepareForShutdown() signal, polling instead.
2024-01-18 15:01:24,367 WARNING - To enable monitoring the PrepareForShutdown() signal instead of polling please install the python3-gi package

I also have that in my journal logs:

systemd[1]: Starting systemd-logind.service - User Login Management...
(d-logind)[1994541]: systemd-logind.service: Failed to set up mount namespacing: Permission denied
(d-logind)[1994541]: systemd-logind.service: Failed at step NAMESPACE spawning /lib/systemd/systemd-logind: Permission denied
systemd[1]: systemd-logind.service: Main process exited, code=exited, status=226/NAMESPACE
systemd[1]: systemd-logind.service: Failed with result 'exit-code'.
systemd[1]: Failed to start systemd-logind.service - User Login Management.
systemd[1]: systemd-logind.service: Scheduled restart job, restart counter is at 1.
systemd[1]: Stopped systemd-logind.service - User Login Management.
systemd[1]: <email address hidden> - Load Kernel Module drm was skipped because of an unmet condition check (ConditionCapability=CAP_SYS_MODULE).

and

[system] Failed to activate service 'org.freedesktop.login1': timed out (service_start_timeout=25000ms)
[system] Rejected: destination has a full message queue, 0 matched rules; type="error", sender="(unset)" ((bus)) interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.TimedOut" requested_reply="1" destination=":1.1" (uid=0 pid=115 comm="/usr/bin/python3 /usr/share/unattended-upgrades/un")
(last line is repeated 9 times in total)

Unfortunately I can't really go back and see when this started. Considering the total CPU time and the average CPU usage (which seems to be slightly above 50% in practice, with peaks at 100%), the issue might be present since the machine was booted.

However I now see the link with an issue I've been seeing for a long time on the host in dmesg:

audit: type=1400 audit(1717098847.156:4846706): apparmor="DENIED" operation="mount" info="failed flags match" error=-13 profile="lxc-container-default-cgns" name="/" pid=840997 comm="(d-logind)" flags="rw, rslave"

I found some related topics which indicate I'm not entirely alone but I really can't tell if the bug initially reported here and mine are the same. I think the universal teaching here is that there can be loops for many different reasons, including maybe through dbus and service activation.