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

Sun Dec 22 00:20:11 GMT 2024

On 12/21/24 04:37, Luca Boccassi wrote:
> Does it work if you boot in permissive mode or with selinux disabled?

I am able to reproduce this in a trixie VM.  I used one created by sbuild
~months ago that I've been updating.  Then, I mostly-followed [1].
Specifically, I:

apt-get install systemd-resolved
reboot
apt-get install selinux-basics selinux-policy-default auditd
selinux-activate
reboot
(let relabel finish)
(let automatic reboot get to grub)
set enforcing=1 at the grub menu
journalctl -b -u systemd-resolved.service

I observe one restart of systemd-resolved, before it works.  There are avc warnings here, but they actually precede
the systemd-resolved startup:

Dec 21 20:21:58 host kernel: audit: type=1400 audit(1734812518.076:5): avc:  denied  { watch } for  pid=300 comm="systemd-resolve" path="/run/systemd" dev="tmpfs" ino=382 scontext=system_u:system_r:systemd_resolved_t:s0 tcontext=system_u:object_r:init_runtime_t:s0 tclass=dir permissive=0
Dec 21 20:21:57 host systemd[1]: Finished systemd-udev-trigger.service - Coldplug All udev Devices.
Dec 21 20:21:57 host systemd[1]: Starting ifupdown-pre.service - Helper to synchronize boot up for ifupdown...
Dec 21 20:21:58 host systemd[1]: Finished systemd-sysctl.service - Apply Kernel Variables.
Dec 21 20:21:58 host systemd[1]: Finished systemd-random-seed.service - Load/Save OS Random Seed.
Dec 21 20:21:58 host systemd[1]: Finished systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully.
Dec 21 20:21:58 host systemd[1]: systemd-sysusers.service - Create System Users was skipped because no trigger condition checks were met.
Dec 21 20:21:58 host systemd[1]: Starting systemd-resolved.service - Network Name Resolution...
Dec 21 20:21:58 host systemd[1]: Starting systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev...
Dec 21 20:21:58 host systemd-resolved[300]: Positive Trust Anchors:
Dec 21 20:21:58 host systemd-resolved[300]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d
Dec 21 20:21:58 host systemd-resolved[300]: 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
Dec 21 20:21:58 host systemd[1]: Finished systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev.
Dec 21 20:21:58 host systemd[1]: Reached target local-fs-pre.target - Preparation for Local File Systems.
Dec 21 20:21:58 host systemd[1]: Reached target local-fs.target - Local File Systems.
Dec 21 20:21:58 host systemd[1]: Listening on systemd-sysext.socket - System Extension Image Management.
Dec 21 20:21:58 host systemd[1]: apparmor.service - Load AppArmor profiles was skipped because of an unmet condition check (ConditionSecurity=apparmor).
Dec 21 20:21:58 host systemd[1]: selinux-autorelabel-mark.service - Mark the need to relabel after reboot was skipped because of an unmet condition check (ConditionSecurity=!selinux).
Dec 21 20:21:58 host systemd[1]: Starting systemd-binfmt.service - Set Up Additional Binary Formats...
Dec 21 20:21:58 host systemd-resolved[300]: Using system hostname 'host'.
Dec 21 20:21:58 host systemd-resolved[300]: Could not create manager: Permission denied
Dec 21 20:21:58 host systemd[1]: Starting systemd-udevd.service - Rule-based Manager for Device Events and Files...
Dec 21 20:21:58 host systemd[1]: systemd-resolved.service: Main process exited, code=exited, status=1/FAILURE
Dec 21 20:21:58 host systemd[1]: systemd-resolved.service: Failed with result 'exit-code'.
Dec 21 20:21:58 host systemd[1]: Failed to start systemd-resolved.service - Network Name Resolution.
Dec 21 20:21:58 host systemd[1]: systemd-resolved.service: Scheduled restart job, restart counter is at 1.
Dec 21 20:21:58 host systemd[1]: proc-sys-fs-binfmt_misc.automount: Got automount request for /proc/sys/fs/binfmt_misc, triggered by 306 (systemd-binfmt)
Dec 21 20:21:58 host systemd[1]: Starting systemd-resolved.service - Network Name Resolution...
Dec 21 20:21:58 host systemd-udevd[307]: Using default interface naming scheme 'v257'.
Dec 21 20:21:58 host systemd[1]: Finished systemd-journal-flush.service - Flush Journal to Persistent Storage.
Dec 21 20:21:58 host systemd[1]: Starting systemd-tmpfiles-setup.service - Create System Files and Directories...
Dec 21 20:21:58 host systemd[1]: Started systemd-udevd.service - Rule-based Manager for Device Events and Files.
Dec 21 20:21:58 host systemd-tmpfiles[316]: /usr/lib/tmpfiles.d/legacy.conf:14: Duplicate line for path "/run/lock", ignoring.
Dec 21 20:21:58 host systemd-tmpfiles[316]: Failed to open path '/etc/profile.d': Permission denied
Dec 21 20:21:58 host systemd-tmpfiles[316]: Failed to open path '/var/spool/cron': Permission denied
Dec 21 20:21:58 host systemd-tmpfiles[316]: Failed to fstat(/root/.ssh): Permission denied
Dec 21 20:21:58 host systemd-tmpfiles[316]: Failed to fstat(/var/lib/systemd/network): Permission denied
Dec 21 20:21:58 host kernel: audit: type=1400 audit(1734812518.176:6): avc:  denied  { relabelfrom } for  pid=316 comm="systemd-tmpfile" name="root" dev="sda1" ino=524306 scontext=system_u:system_r:systemd_tmpfiles_t:s0 tcontext=unconfined_u:object_r:user_home_dir_t:s0 tclass=dir permissive=0
Dec 21 20:21:58 host systemd[1]: Finished systemd-tmpfiles-setup.service - Create System Files and Directories.
Dec 21 20:21:58 host systemd[1]: Found device dev-ttyS0.device - /dev/ttyS0.
Dec 21 20:21:58 host systemd[1]: Starting audit-rules.service - Load Audit Rules...
Dec 21 20:21:58 host systemd[1]: ldconfig.service - Rebuild Dynamic Linker Cache was skipped because no trigger condition checks were met.
Dec 21 20:21:58 host systemd[1]: systemd-firstboot.service - First Boot Wizard was skipped because of an unmet condition check (ConditionFirstBoot=yes).
Dec 21 20:21:58 host systemd[1]: first-boot-complete.target - First Boot Complete was skipped because of an unmet condition check (ConditionFirstBoot=yes).
Dec 21 20:21:58 host systemd[1]: systemd-journal-catalog-update.service - Rebuild Journal Catalog was skipped because of an unmet condition check (ConditionNeedsUpdate=/var).
Dec 21 20:21:58 host systemd[1]: systemd-machine-id-commit.service - Save Transient machine-id to Disk was skipped because of an unmet condition check (ConditionPathIsMountPoint=/etc/machine-id).
Dec 21 20:21:58 host systemd[1]: systemd-update-done.service - Update is Completed was skipped because no trigger condition checks were met.
Dec 21 20:21:58 host kernel: sd 0:0:0:0: Attached scsi generic sg0 type 0
Dec 21 20:21:58 host kernel: sr 1:0:0:0: Attached scsi generic sg1 type 5
Dec 21 20:21:58 host kernel: input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input4
Dec 21 20:21:58 host augenrules[337]: /usr/sbin/augenrules: No change
Dec 21 20:21:58 host augenrules[361]: No rules
Dec 21 20:21:58 host augenrules[361]: enabled 0
Dec 21 20:21:58 host augenrules[361]: failure 1
Dec 21 20:21:58 host augenrules[361]: pid 0
Dec 21 20:21:58 host augenrules[361]: rate_limit 0
Dec 21 20:21:58 host augenrules[361]: backlog_limit 8192
Dec 21 20:21:58 host augenrules[361]: lost 0
Dec 21 20:21:58 host augenrules[361]: backlog 0
Dec 21 20:21:58 host augenrules[361]: backlog_wait_time 15000
Dec 21 20:21:58 host augenrules[361]: backlog_wait_time_actual 0
Dec 21 20:21:58 host augenrules[361]: enabled 0
Dec 21 20:21:58 host augenrules[361]: failure 1
Dec 21 20:21:58 host augenrules[361]: pid 0
Dec 21 20:21:58 host augenrules[361]: rate_limit 0
Dec 21 20:21:58 host augenrules[361]: backlog_limit 8192
Dec 21 20:21:58 host augenrules[361]: lost 0
Dec 21 20:21:58 host augenrules[361]: backlog 0
Dec 21 20:21:58 host augenrules[361]: backlog_wait_time 15000
Dec 21 20:21:58 host augenrules[361]: backlog_wait_time_actual 0
Dec 21 20:21:58 host augenrules[361]: enabled 0
Dec 21 20:21:58 host augenrules[361]: failure 1
Dec 21 20:21:58 host augenrules[361]: pid 0
Dec 21 20:21:58 host augenrules[361]: rate_limit 0
Dec 21 20:21:58 host augenrules[361]: backlog_limit 8192
Dec 21 20:21:58 host augenrules[361]: lost 0
Dec 21 20:21:58 host augenrules[361]: backlog 0
Dec 21 20:21:58 host augenrules[361]: backlog_wait_time 60000
Dec 21 20:21:58 host augenrules[361]: backlog_wait_time_actual 0
Dec 21 20:21:58 host systemd[1]: audit-rules.service: Deactivated successfully.
Dec 21 20:21:58 host systemd[1]: Finished audit-rules.service - Load Audit Rules.
Dec 21 20:21:58 host systemd[1]: Starting auditd.service - Security Audit Logging Service...
Dec 21 20:21:58 host kernel: ACPI: button: Power Button [PWRF]
Dec 21 20:21:58 host kernel: input: PC Speaker as /devices/platform/pcspkr/input/input5
Dec 21 20:21:58 host kernel: bochs-drm 0000:00:02.0: vgaarb: deactivate vga console
Dec 21 20:21:58 host kernel: parport_pc 00:03: reported by Plug and Play ACPI
Dec 21 20:21:58 host kernel: parport0: PC-style at 0x378, irq 7 [PCSPP,TRISTATE]
Dec 21 20:21:58 host kernel: Console: switching to colour dummy device 80x25
Dec 21 20:21:58 host kernel: [drm] Found bochs VGA, ID 0xb0c5.
Dec 21 20:21:58 host kernel: [drm] Framebuffer size 16384 kB @ 0xfd000000, mmio @ 0xfebd0000.
Dec 21 20:21:58 host kernel: [drm] Found EDID data blob.
Dec 21 20:21:58 host kernel: [drm] Initialized bochs-drm 1.0.0 for 0000:00:02.0 on minor 0
Dec 21 20:21:58 host kernel: fbcon: bochs-drmdrmfb (fb0) is primary device
Dec 21 20:21:58 host kernel: Console: switching to colour frame buffer device 160x50
Dec 21 20:21:58 host kernel: bochs-drm 0000:00:02.0: [drm] fb0: bochs-drmdrmfb frame buffer device
Dec 21 20:21:58 host kernel: powernow_k8: Power state transitions not supported
Dec 21 20:21:58 host kernel: powernow_k8: Power state transitions not supported
Dec 21 20:21:58 host auditd[372]: No plugins found, not dispatching events
Dec 21 20:21:58 host systemd[1]: Started auditd.service - Security Audit Logging Service.
Dec 21 20:21:58 host auditd[372]: Init complete, auditd 4.0.2 listening for events (startup state enable)
Dec 21 20:21:58 host kernel: ppdev: user-space parallel port driver
Dec 21 20:21:58 host systemd[1]: Finished ifupdown-pre.service - Helper to synchronize boot up for ifupdown.
Dec 21 20:21:58 host systemd[1]: Starting networking.service - Raise network interfaces...
Dec 21 20:21:58 host dhclient[396]: Internet Systems Consortium DHCP Client 4.4.3-P1
Dec 21 20:21:58 host ifup[396]: Internet Systems Consortium DHCP Client 4.4.3-P1
Dec 21 20:21:58 host ifup[396]: Copyright 2004-2022 Internet Systems Consortium.
Dec 21 20:21:58 host ifup[396]: All rights reserved.
Dec 21 20:21:58 host ifup[396]: For info, please visit https://www.isc.org/software/dhcp/
Dec 21 20:21:58 host dhclient[396]: Copyright 2004-2022 Internet Systems Consortium.
Dec 21 20:21:58 host dhclient[396]: All rights reserved.
Dec 21 20:21:58 host dhclient[396]: For info, please visit https://www.isc.org/software/dhcp/
Dec 21 20:21:58 host dhclient[396]:
Dec 21 20:21:58 host ifup[405]: mkdir: cannot create directory '/run/systemd/resolve': Permission denied
Dec 21 20:21:58 host ifup[406]: chown: cannot access '/run/systemd/resolve/netif': Permission denied
Dec 21 20:21:58 host dhclient[396]: Listening on LPF/eth0/52:54:00:12:34:56
Dec 21 20:21:58 host ifup[396]: Listening on LPF/eth0/52:54:00:12:34:56
Dec 21 20:21:58 host ifup[396]: Sending on   LPF/eth0/52:54:00:12:34:56
Dec 21 20:21:58 host ifup[396]: Sending on   Socket/fallback
Dec 21 20:21:58 host ifup[396]: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 3
Dec 21 20:21:58 host dhclient[396]: Sending on   LPF/eth0/52:54:00:12:34:56
Dec 21 20:21:58 host ifup[396]: DHCPOFFER of 10.0.2.15 from 10.0.2.2
Dec 21 20:21:58 host ifup[396]: DHCPREQUEST for 10.0.2.15 on eth0 to 255.255.255.255 port 67
Dec 21 20:21:58 host ifup[396]: DHCPACK of 10.0.2.15 from 10.0.2.2
Dec 21 20:21:58 host dhclient[396]: Sending on   Socket/fallback
Dec 21 20:21:58 host dhclient[396]: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 3
Dec 21 20:21:58 host dhclient[396]: DHCPOFFER of 10.0.2.15 from 10.0.2.2
Dec 21 20:21:58 host dhclient[396]: DHCPREQUEST for 10.0.2.15 on eth0 to 255.255.255.255 port 67
Dec 21 20:21:58 host dhclient[396]: DHCPACK of 10.0.2.15 from 10.0.2.2
Dec 21 20:21:58 host ifup[422]: mkdir: cannot create directory '/run/systemd/resolve': Permission denied
Dec 21 20:21:58 host ifup[423]: chown: cannot access '/run/systemd/resolve/netif': Permission denied
Dec 21 20:21:58 host ifup[413]: /usr/sbin/dhclient-script: 95: /etc/dhcp/dhclient-exit-hooks.d/resolved: cannot create /run/systemd/resolve/netif/2: Permission denied
Dec 21 20:21:58 host ifup[432]: chown: cannot access '/run/systemd/resolve/netif/2': Permission denied
Dec 21 20:21:58 host dhclient[396]: bound to 10.0.2.15 -- renewal in 32499 seconds.
Dec 21 20:21:58 host ifup[396]: bound to 10.0.2.15 -- renewal in 32499 seconds.
Dec 21 20:21:58 host systemd[1]: Finished networking.service - Raise network interfaces.
Dec 21 20:21:58 host systemd[1]: Mounting proc-sys-fs-binfmt_misc.mount - Arbitrary Executable File Formats File System...
Dec 21 20:21:58 host systemd[1]: Mounting shared.mount - /shared...
Dec 21 20:21:58 host kernel: 9pnet_virtio: no channels available for device sbuild-qemu
Dec 21 20:21:58 host mount[458]: mount: /shared: special device sbuild-qemu does not exist.
Dec 21 20:21:58 host mount[458]:        dmesg(1) may have more information after failed mount system call.
Dec 21 20:21:58 host systemd[1]: Mounted proc-sys-fs-binfmt_misc.mount - Arbitrary Executable File Formats File System.
Dec 21 20:21:58 host systemd[1]: shared.mount: Mount process exited, code=exited, status=32/n/a
Dec 21 20:21:58 host systemd[1]: shared.mount: Failed with result 'exit-code'.
Dec 21 20:21:58 host systemd[1]: Failed to mount shared.mount - /shared.
Dec 21 20:21:58 host systemd[1]: Finished systemd-binfmt.service - Set Up Additional Binary Formats.
Dec 21 20:21:59 host systemd-resolved[308]: Positive Trust Anchors:
Dec 21 20:21:59 host systemd-resolved[308]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d
Dec 21 20:21:59 host systemd-resolved[308]: 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
Dec 21 20:21:59 host systemd-resolved[308]: Using system hostname 'host'.
Dec 21 20:21:59 host systemd[1]: Started systemd-resolved.service - Network Name Resolution.

Motivated by the above, I added a `After=systemd-tmpfiles-setup.service`
dependency on systemd-resolved and systemd-timesyncd. Booting with this
change has so far resolved my issue.

It's still not clear to me what exactly systemd-tmpfiles is doing, but it is
apparently required.

Best,
Antonio

[1] https://wiki.debian.org/SELinux/Setup

-------------- 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/e57c4294/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/e57c4294/attachment-0001.sig>