systemctl daemon-reexec forgets running services and starts everything new
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
systemd |
Fix Released
|
Unknown
|
|||
systemd (Ubuntu) |
Fix Released
|
Medium
|
Unassigned | ||
Jammy |
Fix Released
|
Medium
|
Unassigned | ||
Lunar |
Fix Released
|
Medium
|
Unassigned |
Bug Description
[Impact]
Depending on the contents of /proc/cmdline, when systemd is re-executed with systemctl daemon-reexec, the --deserialize flag may be ignored because it was added after the other arguments. For example, if /proc/cmdline contains ---, then the re-exec cmdline might look like:
$ cat /proc/1/cmdline | tr '\0' '\n'
/lib/systemd/
---
splash
--system
--deserialize
54
This causes systemd not to process the --deserialize 54 argument, causing it to start with a fresh state. This can cause all kinds of problems, and one easy symptom to see is many lines in the journal like:
"$service.service: Found left-over process $pid ($service) in control group while starting unit. Ignoring."
[Test Plan]
1. (Only needed if your test system is not already affected) Edit the kernel command line to contain '---' at the end, which would trigger the bug. This can be done by appending '---' to GRUB_CMDLINE_
2. After enabling -proposed, install systemd:
$ apt install systemd -y
3. Check that the systemd.postinst script skipped the daemon-reexec call, and instead indicated a reboot is required:
$ grep -Fsx systemd /run/reboot-
systemd
4. Reboot.
5. Try to re-exec systemd, and check that there are not tons of "left-over process" log messages:
$ systemctl daemon-reexec
$ journalctl --grep "Found left-over process" -b 0
6. Also confirm that the ordering of /proc/1/cmdline is correct, i.e. that --deserialize $fd comes before args from /proc/cmdline:
$ cat /proc/1/cmdline | tr '\0' '\n'
[Where problems could occur]
There are two changes for this bug. First is the patch against systemd itself, which changes the ordering of arguments on the systemd commandline. This change simply makes it so that systemd's own arguments are always put first on it's re-exec commandline, and that anything from /proc/cmdline is appended after. Any regressions caused by this would also be seen in systemctl daemon-reexec invocations.
The second change is in systemd.postinst, which skips the systemctl daemon-reexec call when upgrading from versions of systemd that could hit this bug. Regressions caused by this would be seen during package upgrades.
[Original Description]
# Our problem #
During a regular update of our container environment, `systemd` (and the related packages libpam-systemd, libsystemd0, libudev1, systemd-sysv and udev) were updated from `249.11-0ubuntu3.6` to `249.11-
In my opinion, the update was not the problem because we've tried downgrading and tried these versions: (current) `249.11-
# Symptoms #
The `/var/lib/
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: Starting Create Volatile Files and Directories...
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: systemd-
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: This usually indicates unclean termination of a previous run, or service implementation deficiencies.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: systemd-
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: This usually indicates unclean termination of a previous run, or service implementation deficiencies.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: systemd-
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: This usually indicates unclean termination of a previous run, or service implementation deficiencies.
And...
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: Reached target System Initialization.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: Started Daily apt download activities.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: Started Daily apt upgrade and clean activities.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: Started Daily dpkg database backup timer.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: Started Periodic ext4 Online Metadata Check for All Filesystems.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: Condition check resulted in Discard unused blocks once a week being skipped.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: Started Daily rotation of log files.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: Started Daily man-db regeneration.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: Started Message of the Day.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: Started Clean PHP session files every 30 mins.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: Started Update the plocate database daily.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: Started Daily Cleanup of Temporary Directories.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: Reached target Basic System.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: System is tainted: cgroupsv1
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: Reached target Timer Units.
And...
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: atd.service: Found left-over process 206 (atd) in control group while starting unit. Ignoring.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: This usually indicates unclean termination of a previous run, or service implementation deficiencies.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: Starting Deferred execution scheduler...
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: cron.service: Found left-over process 164 (cron) in control group while starting unit. Ignoring.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: This usually indicates unclean termination of a previous run, or service implementation deficiencies.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: Started Regular background program processing daemon.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: dbus.service: Found left-over process 177 (dbus-daemon) in control group while starting unit. Ignoring.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: This usually indicates unclean termination of a previous run, or service implementation deficiencies.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: Started D-Bus System Message Bus.
And...
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: rsyslog.service: Found left-over process 204 (rsyslogd) in control group while starting unit. Ignoring.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: atd.service: Failed with result 'exit-code'.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: atd.service: Unit process 206 (atd) remains running after unit stopped.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: apache2.service: Found left-over process 382 (apache2) in control group while starting unit. Ignoring.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: This usually indicates unclean termination of a previous run, or service implementation deficiencies.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: apache2.service: Found left-over process 392 (apache2) in control group while starting unit. Ignoring.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: This usually indicates unclean termination of a previous run, or service implementation deficiencies.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: apache2.service: Found left-over process 397 (apache2) in control group while starting unit. Ignoring.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: This usually indicates unclean termination of a previous run, or service implementation deficiencies.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: apache2.service: Found left-over process 3052 (apache2) in control group while starting unit. Ignoring.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: This usually indicates unclean termination of a previous run, or service implementation deficiencies.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: Starting The Apache HTTP Server...
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: Stopped Deferred execution scheduler.
Mar 31 12:51:39 FQDN_REDACTED systemd[1]: atd.service: Found left-over process 206 (atd) in control group while starting unit. Ignoring.
And...
Mar 31 12:51:40 FQDN_REDACTED sshd[31772]: error: Bind to port 22 on 0.0.0.0 failed: Address already in use.
And...
Mar 31 12:52:06 FQDN_REDACTED systemd[1]: Started The Salt Minion.
Mar 31 12:52:06 FQDN_REDACTED salt-minion[32339]: The Salt Minion is shutdown.
Mar 31 12:52:11 FQDN_REDACTED systemd[1]: salt-minion.
Mar 31 12:52:11 FQDN_REDACTED systemd[1]: salt-minion.
Mar 31 12:52:11 FQDN_REDACTED systemd[1]: salt-minion.
Mar 31 12:52:11 FQDN_REDACTED systemd[1]: salt-minion.
Other internal `systemd` process were started again:
root 1 0.0 0.1 101204 12444 ? Ss 10:19 0:03 /lib/systemd/
root 75 0.0 0.1 31440 13484 ? Ss 10:19 0:00 /lib/systemd/
systemd+ 159 0.0 0.0 16124 8004 ? Ss 10:19 0:00 /lib/systemd/
message+ 177 0.0 0.0 8252 4440 ? Ss 10:19 0:00 @dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-
root 205 0.0 0.0 14908 6464 ? Ss 10:19 0:00 /lib/systemd/
systemd+ 223 0.0 0.1 25268 12592 ? Ss 10:19 0:00 /lib/systemd/
root 31424 0.0 0.1 31424 13636 ? Ss 12:51 0:00 /lib/systemd/
systemd+ 31636 0.0 0.0 16124 6588 ? Ss 12:51 0:00 /lib/systemd/
message+ 31639 0.0 0.0 8124 3804 ? Ss 12:51 0:00 @dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-
root 31682 0.0 0.0 14908 6480 ? Ss 12:51 0:00 /lib/systemd/
systemd+ 31686 0.0 0.1 25268 12580 ? Ss 12:51 0:00 /lib/systemd/
root 32087 0.0 0.0 21436 5252 ? Ss 12:51 0:00 /lib/systemd/
You can either kill all the old processes and restart them, and then everything is fine. Or you can reboot the container. Besides that `systemctl daemon-reexec` the `systemd` version is running fine. `systemctl daemon-reload` is working like a charme.
# Normal case #
In the normal case a `systemctl daemon-reexec` just prints only a few lines:
Mar 31 14:21:58 FQDN_REDACTED systemd[1]: Reexecuting.
Mar 31 14:21:58 FQDN_REDACTED systemd[1]: systemd 249.11-0ubuntu3.7 running in system mode (+PAM +AUDIT +SELINUX +APPARMOR +IMA +SMACK +SECCOMP +GCRYPT +GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP +LIBFDISK +PCRE2 -PWQUALITY -P11KIT -QRENCODE +BZIP2 +LZ4 +XZ +ZLIB +ZSTD -XKBCOMMON +UTMP +SYSVINIT default-
Mar 31 14:21:58 FQDN_REDACTED systemd[1]: Detected architecture x86-64.
# Testcase #
Doing a `systemctl daemon-restart` and `ssh localhost` shows the problem. `systemctl` removes the directory `/run/sshd` during the reexec and `ssh` will refuse further connects because the directory is missing.
$ systemctl daemon-restart
$ ssh root@localhost
kex_exchange_
Connection reset by 127.0.0.1 port 22
$
Killing the old instance of SSH and restarting it will work.
# Some details to the hardware #
Our metal runs OpenVZ/Virtuozzo with this kernel (without any problems):
> Linux FQDN_REDACTED 3.10.0-
The container with the `systemctl daemon-reexec` problem reports the following kernel:
Linux FQDN_REDACTED 5.4.0 #1 SMP Thu Apr 22 16:18:59 MSK 2021 x86_64 x86_64 x86_64 GNU/Linux
# Upshot #
* Can somebody help me with this issue?
* Why is `systemctl` losing its internal state about the running processes/services?
* Why is `systemctl` restarting everything?
Related branches
- Lukas Märdian: Approve
-
Diff: 434 lines (+299/-55)9 files modifieddebian/patches/lp2009743/network-dhcp4-do-not-ignore-the-gateway-even-if-the-desti.patch (+60/-0)
debian/patches/lp2009743/test-network-add-one-more-testcase-for-DHCPv4-classless-r.patch (+36/-0)
debian/patches/lp2013543-core-reorder-systemd-arguments-on-reexec.patch (+58/-0)
debian/patches/lp2028180-udev-rules-fix-nvme-symlink-creation-on-namespace-changes.patch (+59/-0)
debian/patches/lp2031683-sd-bus-bus_message_type_from_string-is-not-pure.patch (+62/-0)
debian/patches/series (+5/-1)
debian/systemd.postinst (+18/-15)
debian/tests/tests-in-lxd (+1/-1)
dev/null (+0/-38)
- Lukas Märdian: Approve
-
Diff: 796 lines (+623/-45)16 files modifieddebian/patches/lp1977630-fix_machinectl_pull_tar.patch (+81/-0)
debian/patches/lp1978079-efi-pstore-not-cleared-on-boot.patch (+5/-4)
debian/patches/lp1991829-add-CAP_LINUX_IMMUTABLE-to-systemd-machined-so-it-ca.patch (+29/-0)
debian/patches/lp1999275/binfmt-check-if-binfmt-is-mounted-before-applying-rules.patch (+80/-0)
debian/patches/lp1999275/binfmt-util-also-check-if-binfmt-is-mounted-in-read-write.patch (+41/-0)
debian/patches/lp1999275/binfmt-util-split-out-binfmt_mounted.patch (+69/-0)
debian/patches/lp1999275/unit-check-more-specific-path-to-be-written-by-systemd-bi.patch (+26/-0)
debian/patches/lp2009743/network-dhcp4-do-not-ignore-the-gateway-even-if-the-desti.patch (+59/-0)
debian/patches/lp2009743/test-network-add-one-more-testcase-for-DHCPv4-classless-r.patch (+33/-0)
debian/patches/lp2013543-core-reorder-systemd-arguments-on-reexec.patch (+58/-0)
debian/patches/lp2025563-shutdown-get-only-active-md-arrays.patch (+67/-0)
debian/patches/lp2028180-udev-rules-fix-nvme-symlink-creation-on-namespace-changes.patch (+47/-0)
debian/patches/series (+11/-1)
debian/systemd.postinst (+16/-1)
debian/tests/tests-in-lxd (+1/-1)
dev/null (+0/-38)
- Lukas Märdian: Approve
-
Diff: 356 lines (+271/-1)11 files modifieddebian/changelog (+30/-0)
debian/libsystemd-dev.install (+1/-0)
debian/patches/lp2009743/network-dhcp4-do-not-ignore-the-gateway-even-if-the-desti.patch (+57/-0)
debian/patches/lp2009743/test-network-add-one-more-testcase-for-DHCPv4-classless-r.patch (+33/-0)
debian/patches/lp2013543-core-reorder-systemd-arguments-on-reexec.patch (+57/-0)
debian/patches/meson.build-disable-Wformat-overflow-on-gcc-with-O3.patch (+26/-0)
debian/patches/series (+4/-0)
debian/rules (+1/-0)
debian/systemd.postinst (+17/-1)
debian/tests/build-with-static-libsystemd (+38/-0)
debian/tests/control (+7/-0)
tags: | added: container |
affects: | sagemath (Ubuntu) → systemd (Ubuntu) |
Changed in systemd (Ubuntu Jammy): | |
status: | Confirmed → Incomplete |
Changed in systemd (Ubuntu): | |
status: | Incomplete → New |
Changed in systemd (Ubuntu Jammy): | |
status: | Incomplete → New |
Changed in systemd (Ubuntu): | |
status: | New → Confirmed |
Changed in systemd (Ubuntu Jammy): | |
status: | New → Confirmed |
Changed in systemd (Ubuntu): | |
importance: | Undecided → Medium |
Changed in systemd (Ubuntu Jammy): | |
importance: | Undecided → Medium |
Changed in systemd: | |
status: | Unknown → Fix Released |
Changed in systemd (Ubuntu Lunar): | |
status: | New → Triaged |
importance: | Undecided → Medium |
Changed in systemd (Ubuntu): | |
status: | Triaged → Fix Committed |
Changed in systemd (Ubuntu Lunar): | |
status: | Triaged → In Progress |
Changed in systemd (Ubuntu Jammy): | |
status: | Triaged → In Progress |
To clarify, you are saying that this issue occurs any time you run `systemctl daemon-reexec`, right? It is not isolated to that command being run during a package upgrade?
I am not familiar with OpenVZ, but I am confused by the kernel situation. Are you saying that the containers which are running Ubuntu (and where you are seeing this problem) are running different kernels than the host?
Like I said, I am not familiar with OpenVZ, but from my understanding of other container environments like LXD, I would expect the containers to share the host's kerenl (and therefore report the same uname -a output).