DynamicUser services can not access dbus since systemd 255

[yu-re-ka]

there is an issue with DynamicUser services accessing dbus since systemd 255 was merged

old:

$ init --version
systemd 254 (254.6)
+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 +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -XKBCOMMON +UTMP -SYSVINIT default-hierarchy=unified

$ sudo systemd-run -p DynamicUser=1 --collect --pty systemctl is-system-running
Running as unit: run-u57.service
Press ^] three times within 1s to disconnect TTY.
degraded

$

new:

$ init --version
systemd 255 (255.2)
+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 +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -XKBCOMMON +UTMP -SYSVINIT default-hierarchy=unified

$ sudo systemd-run -p DynamicUser=1 --collect --pty systemctl is-system-running
Running as unit: run-u3393.service
Press ^] three times within 1s to disconnect TTY.
Failed to query system state: Transport endpoint is not connected
unknown

$ 

@NixOS/systemd

[arianvp]

Could you run with log level set to debug?

[yu-re-ka]

$ sudo systemd-run -E SYSTEMD_LOG_LEVEL=debug -p DynamicUser=1 --collect --pty systemctl is-system-running
Running as unit: run-u63.service
Press ^] three times within 1s to disconnect TTY.
Cannot stat /proc/1/root: No such file or directory
Bus n/a: changing state UNSET → OPENING
sd-bus: starting bus by connecting to /run/dbus/system_bus_socket...
Bus n/a: changing state OPENING → AUTHENTICATING
Bus n/a: changing state AUTHENTICATING → HELLO
Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=Hello cookie=1 reply_cookie=0 signature=n/a error-name=n/a error-message=n/a
Got message type=method_return sender=org.freedesktop.DBus destination=:1.64 path=n/a interface=n/a member=n/a  cookie=1 reply_cookie=1 signature=s error-name=n/a error-message=n/a
Bus n/a: changing state HELLO → RUNNING
Sent message type=method_call sender=n/a destination=org.freedesktop.systemd1 path=/org/freedesktop/systemd1 interface=org.freedesktop.DBus.Properties member=Get cookie=2 reply_cookie=0 signature=ss error-name=n/a error-message=n/a
Got message type=method_return sender=:1.3 destination=:1.64 path=n/a interface=n/a member=n/a  cookie=15023 reply_cookie=2 signature=v error-name=n/a error-message=n/a
degraded
Bus n/a: changing state RUNNING → CLOSED

$ sudo systemd-run -E SYSTEMD_LOG_LEVEL=debug -p DynamicUser=1 --collect --pty systemctl is-system-running
Running as unit: run-u3649.service; invocation ID: 7f3ad242197f4876b40cfa8fc047b1e7
Press ^] three times within 1s to disconnect TTY.
Cannot stat /proc/1/root: Permission denied
Bus n/a: changing state UNSET → OPENING
sd-bus: starting bus by connecting to /run/dbus/system_bus_socket...
Bus n/a: changing state OPENING → AUTHENTICATING
Bus n/a: changing state AUTHENTICATING → HELLO
Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=Hello cookie=1 reply_cookie=0 signature=n/a error-name=n/a error-message=n/a
Bus n/a: changing state HELLO → CLOSING
Failed to query system state: Transport endpoint is not connected
unknown
Bus n/a: changing state CLOSING → CLOSED

[r-vdp]

FWIW, this seems to work for me. I'm using dbus-broker, which might make a difference.

$ sudo systemd-run -E SYSTEMD_LOG_LEVEL=debug -p DynamicUser=1 --collect --pty systemctl is-system-running
Running as unit: run-u47.service
Press ^] three times within 1s to disconnect TTY.
Cannot stat /proc/1/root: Permission denied
Bus n/a: changing state UNSET → OPENING
sd-bus: starting bus by connecting to /run/dbus/system_bus_socket...
Bus n/a: changing state OPENING → AUTHENTICATING
Bus n/a: changing state AUTHENTICATING → HELLO       
Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=Hello cookie=1 reply_cookie=0 signature=n/a error-name=n/a error-message=n/a
Got message type=method_return sender=org.freedesktop.DBus destination=:1.48 path=n/a interface=n/a member=n/a  cookie=4294967295 reply_cookie=1 signature=s error-name=n/a error-message=n/a
Bus n/a: changing state HELLO → RUNNING
Sent message type=method_call sender=n/a destination=org.freedesktop.systemd1 path=/org/freedesktop/systemd1 interface=org.freedesktop.DBus.Properties member=Get cookie=2 reply_cookie=0 signature=ss error-name=n/a error-message=n/a
Got message type=method_return sender=:1.3 destination=:1.48 path=n/a interface=n/a member=n/a  cookie=6177 reply_cookie=2 signature=v error-name=n/a error-message=n/a
running
Bus n/a: changing state RUNNING → CLOSED
$ init --version
systemd 255 (255.2)
+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 +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -XKBCOMMON +UTMP -SYSVINIT default-hierarchy=unified

[flokli]

Peeking at the dbus NixOS module, dbus-broker seems to set LD_LIBRARY_PATH = config.system.nssModules.path, but is configured to never restart, so it also won't be able to make use of newly configured NSS modules.

It's also still trying to talk to nsncd, in addition of having a (possibly outdated) nssModules path set.

I'm currently working on teaching nsncd socket activation, I think I want to move it to DefaultDependencies=no land and start it alongside dbus-broker, hopefully alleviating some of the issues.

[flokli]

Apparently there's other regressions with the switch to dbus-broker too, I opened a PR with a revert for now in #307731.

[SuperSandro2000]

Which ones? There is one other issue open where we have no logs and no reproducer.

[alois31]

Apparently there's other regressions with the switch to dbus-broker too, I opened a PR with a revert for now in #307731.

Given the other comments here (particularly #297756 (comment)) and from testing on my system, this is actually fixed by dbus-broker.

[flokli]

@alois31 @yu-re-ka would you be up to constructing a NixOS test for this / extending our existing set of tests? That way it'd be easy to verify where things are broken and where fixed.

[AndrewKvalheim]

Not sure if this is related, but I started seeing the same symptom after an automatic update this morning from 24.05.5562.1bfbbbe5bbf8 to 24.05.5596.d51c28603def:

Oct 13 04:46:51 systemd[1]: monitor-duration.service: Deactivated successfully.
Oct 13 05:16:55 systemd[1]: monitor-duration.service: Deactivated successfully.
Oct 13 05:46:46 systemd[1]: monitor-duration.service: Deactivated successfully.
-- Boot 7fbbbbd890af4734bafd3da33b1b5517 --
Oct 13 06:16:39 monitor-duration[13940]: Failed to get properties: Transport endpoint is not connected
Oct 13 06:16:39 systemd[1]: Failed to start monitor-duration.service.
Oct 13 06:47:18 monitor-duration[17469]: Failed to get properties: Transport endpoint is not connected
Oct 13 06:47:18 systemd[1]: Failed to start monitor-duration.service.
Oct 13 07:00:34 monitor-duration[18722]: Failed to get properties: Transport endpoint is not connected
Oct 13 07:00:34 systemd[1]: Failed to start monitor-duration.service.

It looks like not much changed so I don’t understand why this suddenly started happening. Switching to dbus-broker made it start working again:

 Cannot stat /proc/1/root: No such file or directory
 Failed to check if we're running in chroot, assuming not: Function not implemented
 Bus n/a: changing state UNSET → OPENING
 sd-bus: starting bus by connecting to /run/dbus/system_bus_socket...
 Bus n/a: changing state OPENING → AUTHENTICATING
 Showing one /org/freedesktop/systemd1/unit/example_2eservice
 Bus n/a: changing state AUTHENTICATING → HELLO
 Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=Hello cookie=1 reply_cookie=0 s>
-Bus n/a: changing state HELLO → CLOSING
+Bus n/a: changing state HELLO → RUNNING
-Failed to get properties: Transport endpoint is not connected
+Got message type=method_return sender=org.freedesktop.DBus destination=:1.31 path=n/a interface=n/a member=n/a  cookie=5107905569 reply_cookie=1 signature=s error-name=n/>
+Sent message type=method_call sender=n/a destination=org.freedesktop.systemd1 path=/org/freedesktop/systemd1/unit/example_2eservice interface=org.freedesktop.DBus.P>
+Got message type=method_return sender=:1.4 destination=:1.31 path=n/a interface=n/a member=n/a  cookie=2769 reply_cookie=2 signature=a{sv} error-name=n/a error-message=n/a
-Bus n/a: changing state CLOSING → CLOSED
+Bus n/a: changing state RUNNING → CLOSED