Bug#1090966: "Could not create manager: Permission denied" maybe selinux related (also affects systemd-timesyncd)

[Antonio Russo]

Package: systemd-resolved
Version: 257.1-1
Severity: normal

Dear maintainer,

I upgraded to 257.1-1, and both systemd-timesyncd and systemd-resolved fail to come up at boot:

systemd[1]: Starting systemd-resolved.service - Network Name Resolution...
systemd[1]: Starting systemd-timesyncd.service - Network Time Synchronization...
systemd[1]: Starting systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev...
systemd[1]: Finished systemd-random-seed.service - Load/Save OS Random Seed.
systemd[1]: Finished systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev.
systemd[1]: Starting systemd-udevd.service - Rule-based Manager for Device Events and Files...
systemd-journald[1924]: Journal started
systemd-journald[1924]: Runtime Journal (/run/log/journal/a79e93a319504207b280effb512d2345) is 8M, max 620.9M, 612.9M free.
systemd-modules-load[1925]: Inserted module 'msr'
systemd-modules-load[1925]: Inserted module 'usbip_core'
systemd-modules-load[1925]: Inserted module 'usbip_host'
lvm[1916]:   2 logical volume(s) in volume group REDACTED
systemd[1]: Started systemd-journald.service - Journal Service.
systemd-timesyncd[1944]: Failed to allocate manager: Permission denied
systemd[1]: systemd-timesyncd.service: Main process exited, code=exited, status=1/FAILURE
systemd[1]: systemd-timesyncd.service: Failed with result 'exit-code'.
systemd[1]: Failed to start systemd-timesyncd.service - Network Time Synchronization.
systemd[1]: Finished lvm2-monitor.service - Monitoring of LVM2 mirrors, snapshots etc. using dmeventd or progress polling.
systemd[1]: systemd-timesyncd.service: Scheduled restart job, restart counter is at 1.
systemd[1]: Reached target local-fs-pre.target - Preparation for Local File Systems.
systemd[1]: Starting systemd-journal-flush.service - Flush Journal to Persistent Storage...
systemd[1]: Starting systemd-timesyncd.service - Network Time Synchronization...
systemd-resolved[1943]: Positive Trust Anchors:
systemd-resolved[1943]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d
systemd-resolved[1943]: Negative trust anchors: home.arpa 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 170.0.0.192.in-addr.arpa 171.0.0.192.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa ipv4only.arpa resolver.arpa corp home internal intranet lan local private test
systemd-journald[1924]: Time spent on flushing to /var/log/journal/a79e93a319504207b280effb512d2345 is 85.680ms for 1256 entries.
systemd-journald[1924]: System Journal (/var/log/journal/a79e93a319504207b280effb512d2345) is 2G, max 4G, 1.9G free.
systemd-journald[1924]: Received client request to flush runtime journal.
kernel: Adding 73400316k swap on REDACTED
kernel: input: Lid Switch as REDACTED
kernel: ACPI: AC: AC Adapter [ACAD] (on-line)
kernel: ACPI: button: Lid Switch [LID0]
kernel: input: Power Button as REDACTED
kernel: ACPI: button: Power Button [PWRB]
mtp-probe[2045]: checking REDACTED
systemd[1]: Finished systemd-udev-trigger.service - Coldplug All udev Devices.
mtp-probe[2044]: checking REDACTED
systemd-udevd[1953]: Using default interface naming scheme 'v257'.
mtp-probe[2045]: bus: REDACTED was not an MTP device
systemd-resolved[1943]: Using system hostname 'REDACTEDHOSTNAME'.
mtp-probe[2044]: bus: REDACTED was not an MTP device
systemd-resolved[1943]: Could not create manager: Permission denied
usbauth[2049]: called by udev with given usb_interface
systemd[1]: Finished nftables.service - nftables.
mtp-probe[2050]: checking REDACTED
kernel: sp5100_tco: SP5100/SB800 TCO WatchDog Timer Driver
kernel: sp5100-tco sp5100-tco: Using 0xfeb00000 for watchdog MMIO address
kernel: sp5100-tco sp5100-tco: initialized. heartbeat=60 sec (nowayout=0)
kernel: ccp 0000:c1:00.2: tee enabled
kernel: ccp 0000:c1:00.2: psp enabled
systemd[1]: systemd-resolved.service: Main process exited, code=exited, status=1/FAILURE
mtp-probe[2051]: checking REDACTED
systemd[1]: systemd-resolved.service: Failed with result 'exit-code'.
usbauth[2052]: called by udev with given usb_interface
systemd[1]: Failed to start systemd-resolved.service - Network Name Resolution.
usbauth[2055]: called by udev with given usb_interface
systemd[1]: systemd-resolved.service: Scheduled restart job, restart counter is at 1.


It retries 5 times, then gives up.  Once I log in, I can restart both of these units, and they come up perfectly fine. (!!)

Also, I'm pretty sure this was working with 257-2.  This particular log is from 257.1-3, but it is not
meaningfully different from any other 257.1-* versions.

I am running with selinux in enforcing mode, but I've run `semodule -DB`, and as you can see, there are
no audit warnings.  So, I'm at a loss for how selinux could be causing the problem here.

I have another machine (which is not running selinux in enforcing mode) that isn't affected by this,
so I'm at a bit of a loss how to debug this.

I tried adding a delay to the restart on systemd-resolved (1 second).  This just slowed down the boot by a few seconds,
delaying bringing up `nss-lookup.target`, which blocks the rest of the boot.

I suspect that timesyncd and resolved have some unstated dependency on something that transitively depends on
nss-lookup.target, possibly only on selinux systems (but again, I don't see how that could be the case,
given the lack of audit errors).  Maybe systemd-tmpfiles is fixing permissions on something?

I'd prefer not to boot this machine up in permissive mode, if possible.

Best,
Antonio
-------------- next part --------------
A non-text attachment was scrubbed...
Name: OpenPGP_0x72DB026E04C1C768.asc
Type: application/pgp-keys
Size: 7680 bytes
Desc: OpenPGP public key
URL: <http://alioth-lists.debian.net/pipermail/pkg-systemd-maintainers/attachments/20241221/34242224/attachment-0001.asc>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: OpenPGP_signature.asc
Type: application/pgp-signature
Size: 833 bytes
Desc: OpenPGP digital signature
URL: <http://alioth-lists.debian.net/pipermail/pkg-systemd-maintainers/attachments/20241221/34242224/attachment-0001.sig>