Bug 2333743

Summary:	systemd-resolved and oom services fail during boot because of race condition between PrivateTmp setup and required mount points being available
Product:	[Fedora] Fedora	Reporter:	Georg Sauthoff <fedora>
Component:	kiwi	Assignee:	Neal Gompa <ngompa13>
Status:	CLOSED ERRATA	QA Contact:	Fedora Extras Quality Assurance <extras-qa>
Severity:	high	Docs Contact:
Priority:	unspecified
Version:	rawhide	CC:	awilliam, daan.j.demeyer, davide, dtardon, fedoraproject, kevin, lnykryn, marcus-schaefer, michel, mpitt, msekleta, ngompa13, ryncsn, suraj.ghimire7, systemd-maint, yuwatana, zbyszek, zpytela
Target Milestone:	---	Keywords:	Regression
Target Release:	---
Hardware:	Unspecified
OS:	Linux
Whiteboard:	CockpitTest
Fixed In Version:	kiwi-10.2.18-1.fc42 kiwi-10.2.18-1.fc41 kiwi-10.2.18-1.el10_1 kiwi-10.2.18-1.fc40 kiwi-10.2.18-1.el10_0 kiwi-10.2.18-1.el9	Doc Type:	If docs needed, set a value
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2025-04-29 20:39:55 UTC	Type:	---
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:
Bug Depends On:	2334015
Bug Blocks:

Description Georg Sauthoff 2024-12-22 13:39:05 UTC

Running Fedora-Cloud-Base-Generic-Rawhide-20241222.n.0.x86_64.qcow2 as a libvirt (kvm) guest exposes a race condition between the service's PrivateTmp=disconnected setup and the required mount points not being available yet, during system boot.

In combination with the immediate restart attempts those 5 attempts all likely fail, too, and thus systemd-resolved.service and systemd-oomd.service quickly fail  to start when the system boots.

As a result name resolution doesn't work, which is quite catastrophic for the common VM guest system.

Reproducible: Sometimes

Steps to Reproduce:
1. download Fedora-Cloud-Base-Generic-Rawhide-20241222.n.0.x86_64.qcow2 from https://kojipkgs.fedoraproject.org/compose/rawhide/latest-Fedora-Rawhide/compose/Cloud/x86_64/images/
2. create a libvirt kvm guest from it via virt-install
3. start it with virsh
4. ssh into it
5. check systemd-resolved and systemd-oomd status and logs
6. dnf update
Actual Results:  
At ssh login systemd already reports failures:

[systemd]
Failed Units: 3
  systemd-oomd.service
  systemd-resolved.service
  systemd-oomd.socket

systemd-resolved.service and systemd-oomd failed like this:

Active: failed (Result: exit-code) since Sun 2024-12-22 12:58:29 UTC; 1min 6s ago

Dec 22 12:31:55 localhost systemd[1]: Starting systemd-oomd.service - Userspace Out-Of-Memory (OOM) Killer...
Dec 22 12:31:55 localhost (emd-oomd)[726]: Failed to create destination mount point node '/run/systemd/mount-rootfs/var/tmp', ignoring: Permission denied
Dec 22 12:31:55 localhost (emd-oomd)[726]: Failed to mount /run/systemd/unit-private-tmp/var-tmp to /run/systemd/mount-rootfs/var/tmp: No such file or directory
Dec 22 12:31:55 localhost (emd-oomd)[726]: systemd-oomd.service: Failed to set up mount namespacing: /var/tmp: No such file or directory
Dec 22 12:31:55 localhost (emd-oomd)[726]: systemd-oomd.service: Failed at step NAMESPACE spawning /usr/lib/systemd/systemd-oomd: No such file or directory

From another boot:

Dec 22 12:58:29 localhost (emd-oomd)[789]: Failed to mount /run/systemd/unit-private-tmp/var-tmp to /run/systemd/mount-rootfs/var/tmp: No such file or directory
Dec 22 12:58:29 localhost (emd-oomd)[789]: systemd-oomd.service: Failed to set up mount namespacing: /var/tmp: No such file or directory
Dec 22 12:58:29 localhost (emd-oomd)[789]: systemd-oomd.service: Failed at step NAMESPACE spawning /usr/lib/systemd/systemd-oomd: No such file or directory
Dec 22 12:58:29 localhost systemd[1]: systemd-oomd.service: Main process exited, code=exited, status=226/NAMESPACE
Dec 22 12:58:29 localhost systemd[1]: systemd-oomd.service: Failed with result 'exit-code'.
Dec 22 12:58:29 localhost systemd[1]: Failed to start systemd-oomd.service - Userspace Out-Of-Memory (OOM) Killer.
Dec 22 12:58:29 localhost audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-oomd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? ad>
Dec 22 12:58:29 localhost systemd[1]: Mounted home.mount - /home.
Dec 22 12:58:29 localhost systemd[1]: Mounted var.mount - /var.
[..]
Dec 22 12:58:29 localhost systemd[1]: systemd-oomd.service: Start request repeated too quickly.
Dec 22 12:58:29 localhost systemd[1]: systemd-oomd.service: Failed with result 'exit-code'.
Dec 22 12:58:29 localhost systemd[1]: Failed to start systemd-oomd.service - Userspace Out-Of-Memory (OOM) Killer.


Similar errors for resolved:

Dec 22 13:08:50 localhost systemd[1]: systemd-resolved.service: Scheduled restart job, restart counter is at 5.
Dec 22 13:08:50 localhost systemd[1]: systemd-resolved.service: Start request repeated too quickly.
Dec 22 13:08:50 localhost systemd[1]: systemd-resolved.service: Failed with result 'exit-code'.
Dec 22 13:08:50 localhost systemd[1]: Failed to start systemd-resolved.service - Network Name Resolution.
Dec 22 13:08:50 localhost systemd[1]: systemd-resolved.service: Start request repeated too quickly.
Dec 22 13:08:50 localhost systemd[1]: systemd-resolved.service: Failed with result 'exit-code'.
Dec 22 13:08:50 localhost systemd[1]: Failed to start systemd-resolved.service - Network Name Resolution.
Dec 22 13:08:51 localhost.localdomain systemd[1]: systemd-resolved.service: Start request repeated too quickly.
Dec 22 13:08:51 localhost.localdomain systemd[1]: systemd-resolved.service: Failed with result 'exit-code'.
Dec 22 13:08:51 localhost.localdomain systemd[1]: Failed to start systemd-resolved.service - Network Name Resolution.


Of course `dnf update`  then also fails due to name-resolution errors.

Expected Results:  
No such errors. Name resolution works out of the box.

Adding some additional ordering for systemd-resolved.service seems to resolve (no pun intended!) this race condition:

cat /etc/systemd/system/systemd-resolved.service.d/workaround.conf 
[Unit]
After=var.mount

Systemd version:
systemd-257.1-1.fc42.x86_64
systemd-resolved-257.1-1.fc42.x86_64

Comment 1 Georg Sauthoff 2024-12-22 13:54:17 UTC

Rebooted several times the VM and the workaround seems to be stable.

After I removed the workaround again the next reboot makes resolved fail again at startup:


Dec 22 13:44:03 localhost systemd-tmpfiles[328]: /usr/lib/tmpfiles.d/var.conf:14: Duplicate line for path "/var/log", ignoring.
Dec 22 13:44:04 localhost systemd[1]: Listening on systemd-oomd.socket - Userspace Out-Of-Memory (OOM) Killer Socket.
Dec 22 13:44:04 localhost systemd[1]: Starting systemd-oomd.service - Userspace Out-Of-Memory (OOM) Killer...
Dec 22 13:44:04 localhost audit[667]: AVC avc:  denied  { add_name } for  pid=667 comm="(emd-oomd)" name="tmp" scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:unlabeled_t:s0 tclass=dir permissi
ve=0
Dec 22 13:44:04 localhost systemd[1]: systemd-oomd.service: Main process exited, code=exited, status=226/NAMESPACE
Dec 22 13:44:04 localhost systemd[1]: systemd-oomd.service: Failed with result 'exit-code'.
Dec 22 13:44:04 localhost systemd[1]: Failed to start systemd-oomd.service - Userspace Out-Of-Memory (OOM) Killer.
Dec 22 13:44:04 localhost audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-oomd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? add
r=? terminal=? res=failed'
Dec 22 13:44:04 localhost systemd[1]: Starting systemd-resolved.service - Network Name Resolution...
Dec 22 13:44:04 localhost audit[711]: AVC avc:  denied  { add_name } for  pid=711 comm="(resolved)" name="tmp" scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:unlabeled_t:s0 tclass=dir permissi
ve=0
Dec 22 13:44:04 localhost audit[711]: SYSCALL arch=c000003e syscall=258 success=no exit=-13 a0=ffffff9c a1=556cf3d49420 a2=1ed a3=0 items=0 ppid=1 pid=711 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid
=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="(resolved)" exe="/usr/lib/systemd/systemd-executor" subj=system_u:system_r:init_t:s0 key=(null)
Dec 22 13:44:04 localhost audit: PROCTITLE proctitle="(resolved)"
Dec 22 13:44:04 localhost (resolved)[711]: Failed to create destination mount point node '/run/systemd/mount-rootfs/var/tmp', ignoring: Permission denied
Dec 22 13:44:04 localhost (resolved)[711]: Failed to mount /run/systemd/unit-private-tmp/var-tmp to /run/systemd/mount-rootfs/var/tmp: No such file or directory
Dec 22 13:44:04 localhost (resolved)[711]: systemd-resolved.service: Failed to set up mount namespacing: /var/tmp: No such file or directory
Dec 22 13:44:04 localhost (resolved)[711]: systemd-resolved.service: Failed at step NAMESPACE spawning /usr/lib/systemd/systemd-resolved: No such file or directory
Dec 22 13:44:04 localhost systemd[1]: systemd-resolved.service: Main process exited, code=exited, status=226/NAMESPACE
Dec 22 13:44:04 localhost systemd[1]: systemd-resolved.service: Failed with result 'exit-code'.
Dec 22 13:44:04 localhost systemd[1]: Failed to start systemd-resolved.service - Network Name Resolution.
Dec 22 13:44:04 localhost audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-resolved comm="systemd" exe="/usr/lib/systemd/systemd" hostname=?
 addr=? terminal=? res=failed'
Dec 22 13:44:04 localhost systemd[1]: systemd-resolved.service: Scheduled restart job, restart counter is at 1.
Dec 22 13:44:04 localhost systemd[1]: Starting systemd-resolved.service - Network Name Resolution...
Dec 22 13:44:04 localhost audit[717]: AVC avc:  denied  { add_name } for  pid=717 comm="(resolved)" name="tmp" scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:unlabeled_t:s0 tclass=dir permissi
ve=0
Dec 22 13:44:04 localhost audit[717]: SYSCALL arch=c000003e syscall=258 success=no exit=-13 a0=ffffff9c a1=55eaafa06420 a2=1ed a3=0 items=0 ppid=1 pid=717 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid
=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="(resolved)" exe="/usr/lib/systemd/systemd-executor" subj=system_u:system_r:init_t:s0 key=(null)
Dec 22 13:44:04 localhost audit: PROCTITLE proctitle="(resolved)"
Dec 22 13:44:04 localhost (resolved)[717]: Failed to create destination mount point node '/run/systemd/mount-rootfs/var/tmp', ignoring: Permission denied
Dec 22 13:44:04 localhost (resolved)[717]: Failed to mount /run/systemd/unit-private-tmp/var-tmp to /run/systemd/mount-rootfs/var/tmp: No such file or directory
Dec 22 13:44:04 localhost (resolved)[717]: systemd-resolved.service: Failed to set up mount namespacing: /var/tmp: No such file or directory
Dec 22 13:44:04 localhost (resolved)[717]: systemd-resolved.service: Failed at step NAMESPACE spawning /usr/lib/systemd/systemd-resolved: No such file or directory
Dec 22 13:44:04 localhost systemd[1]: systemd-resolved.service: Main process exited, code=exited, status=226/NAMESPACE
Dec 22 13:44:04 localhost systemd[1]: systemd-resolved.service: Failed with result 'exit-code'.
Dec 22 13:44:04 localhost systemd[1]: Failed to start systemd-resolved.service - Network Name Resolution.
Dec 22 13:44:04 localhost audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-resolved comm="systemd" exe="/usr/lib/systemd/systemd" hostname=?
 addr=? terminal=? res=failed'
Dec 22 13:44:04 localhost systemd[1]: systemd-resolved.service: Scheduled restart job, restart counter is at 2.
Dec 22 13:44:04 localhost systemd[1]: Starting systemd-resolved.service - Network Name Resolution...
Dec 22 13:44:04 localhost audit[722]: AVC avc:  denied  { add_name } for  pid=722 comm="(resolved)" name="tmp" scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:unlabeled_t:s0 tclass=dir permissi
ve=0
Dec 22 13:44:04 localhost audit[722]: SYSCALL arch=c000003e syscall=258 success=no exit=-13 a0=ffffff9c a1=555c93bc9420 a2=1ed a3=0 items=0 ppid=1 pid=722 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid
=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="(resolved)" exe="/usr/lib/systemd/systemd-executor" subj=system_u:system_r:init_t:s0 key=(null)
Dec 22 13:44:04 localhost audit: PROCTITLE proctitle="(resolved)"
Dec 22 13:44:04 localhost (resolved)[722]: Failed to create destination mount point node '/run/systemd/mount-rootfs/var/tmp', ignoring: Permission denied
Dec 22 13:44:04 localhost (resolved)[722]: Failed to mount /run/systemd/unit-private-tmp/var-tmp to /run/systemd/mount-rootfs/var/tmp: No such file or directory
Dec 22 13:44:04 localhost (resolved)[722]: systemd-resolved.service: Failed to set up mount namespacing: /var/tmp: No such file or directory
Dec 22 13:44:04 localhost (resolved)[722]: systemd-resolved.service: Failed at step NAMESPACE spawning /usr/lib/systemd/systemd-resolved: No such file or directory
Dec 22 13:44:04 localhost systemd[1]: systemd-resolved.service: Main process exited, code=exited, status=226/NAMESPACE
Dec 22 13:44:04 localhost systemd[1]: systemd-resolved.service: Failed with result 'exit-code'.
Dec 22 13:44:04 localhost systemd[1]: Failed to start systemd-resolved.service - Network Name Resolution.
Dec 22 13:44:04 localhost audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-resolved comm="systemd" exe="/usr/lib/systemd/systemd" hostname=?
 addr=? terminal=? res=failed'
Dec 22 13:44:04 localhost systemd[1]: systemd-resolved.service: Scheduled restart job, restart counter is at 3.
Dec 22 13:44:04 localhost systemd[1]: Starting systemd-resolved.service - Network Name Resolution...
Dec 22 13:44:04 localhost audit[727]: AVC avc:  denied  { add_name } for  pid=727 comm="(resolved)" name="tmp" scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:unlabeled_t:s0 tclass=dir permissi
ve=0
Dec 22 13:44:04 localhost audit[727]: SYSCALL arch=c000003e syscall=258 success=no exit=-13 a0=ffffff9c a1=558b9cef6420 a2=1ed a3=0 items=0 ppid=1 pid=727 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid
=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="(resolved)" exe="/usr/lib/systemd/systemd-executor" subj=system_u:system_r:init_t:s0 key=(null)
Dec 22 13:44:04 localhost audit: PROCTITLE proctitle="(resolved)"
Dec 22 13:44:04 localhost (resolved)[727]: Failed to create destination mount point node '/run/systemd/mount-rootfs/var/tmp', ignoring: Permission denied
Dec 22 13:44:04 localhost (resolved)[727]: Failed to mount /run/systemd/unit-private-tmp/var-tmp to /run/systemd/mount-rootfs/var/tmp: No such file or directory
Dec 22 13:44:04 localhost (resolved)[727]: systemd-resolved.service: Failed to set up mount namespacing: /var/tmp: No such file or directory
Dec 22 13:44:04 localhost (resolved)[727]: systemd-resolved.service: Failed at step NAMESPACE spawning /usr/lib/systemd/systemd-resolved: No such file or directory
Dec 22 13:44:04 localhost systemd[1]: systemd-resolved.service: Main process exited, code=exited, status=226/NAMESPACE
Dec 22 13:44:04 localhost systemd[1]: systemd-resolved.service: Failed with result 'exit-code'.
Dec 22 13:44:04 localhost systemd[1]: Failed to start systemd-resolved.service - Network Name Resolution.
Dec 22 13:44:04 localhost audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-resolved comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
Dec 22 13:44:04 localhost systemd[1]: systemd-resolved.service: Scheduled restart job, restart counter is at 4.
Dec 22 13:44:04 localhost systemd[1]: Starting systemd-resolved.service - Network Name Resolution...
Dec 22 13:44:04 localhost audit[731]: AVC avc:  denied  { add_name } for  pid=731 comm="(resolved)" name="tmp" scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:unlabeled_t:s0 tclass=dir permissive=0
Dec 22 13:44:04 localhost audit[731]: SYSCALL arch=c000003e syscall=258 success=no exit=-13 a0=ffffff9c a1=55eec3a91420 a2=1ed a3=0 items=0 ppid=1 pid=731 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="(resolved)" exe="/usr/lib/systemd/systemd-executor" subj=system_u:system_r:init_t:s0 key=(null)
Dec 22 13:44:04 localhost audit: PROCTITLE proctitle="(resolved)"
Dec 22 13:44:04 localhost (resolved)[731]: Failed to create destination mount point node '/run/systemd/mount-rootfs/var/tmp', ignoring: Permission denied
Dec 22 13:44:04 localhost (resolved)[731]: Failed to mount /run/systemd/unit-private-tmp/var-tmp to /run/systemd/mount-rootfs/var/tmp: No such file or directory
Dec 22 13:44:04 localhost (resolved)[731]: systemd-resolved.service: Failed to set up mount namespacing: /var/tmp: No such file or directory
Dec 22 13:44:04 localhost (resolved)[731]: systemd-resolved.service: Failed at step NAMESPACE spawning /usr/lib/systemd/systemd-resolved: No such file or directory
Dec 22 13:44:04 localhost systemd[1]: systemd-resolved.service: Main process exited, code=exited, status=226/NAMESPACE
Dec 22 13:44:04 localhost systemd[1]: systemd-resolved.service: Failed with result 'exit-code'.
Dec 22 13:44:04 localhost systemd[1]: Failed to start systemd-resolved.service - Network Name Resolution.
Dec 22 13:44:04 localhost audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-resolved comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
Dec 22 13:44:04 localhost systemd[1]: systemd-oomd.service: Scheduled restart job, restart counter is at 1.
Dec 22 13:44:04 localhost systemd[1]: systemd-resolved.service: Scheduled restart job, restart counter is at 5.
Dec 22 13:44:04 localhost systemd[1]: Starting systemd-oomd.service - Userspace Out-Of-Memory (OOM) Killer...
Dec 22 13:44:04 localhost systemd[1]: systemd-resolved.service: Start request repeated too quickly.
Dec 22 13:44:04 localhost systemd[1]: systemd-resolved.service: Failed with result 'exit-code'.
Dec 22 13:44:04 localhost systemd[1]: Failed to start systemd-resolved.service - Network Name Resolution.
Dec 22 13:44:04 localhost audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-resolved comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
Dec 22 13:44:04 localhost (emd-oomd)[755]: Failed to create destination mount point node '/run/systemd/mount-rootfs/var/tmp', ignoring: Permission denied
Dec 22 13:44:04 localhost (emd-oomd)[755]: Failed to mount /run/systemd/unit-private-tmp/var-tmp to /run/systemd/mount-rootfs/var/tmp: No such file or directory
Dec 22 13:44:04 localhost (emd-oomd)[755]: systemd-oomd.service: Failed to set up mount namespacing: /var/tmp: No such file or directory
Dec 22 13:44:04 localhost (emd-oomd)[755]: systemd-oomd.service: Failed at step NAMESPACE spawning /usr/lib/systemd/systemd-oomd: No such file or directory
Dec 22 13:44:04 localhost audit[755]: AVC avc:  denied  { add_name } for  pid=755 comm="(emd-oomd)" name="tmp" scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:unlabeled_t:s0 tclass=dir permissive=0
Dec 22 13:44:04 localhost audit[755]: SYSCALL arch=c000003e syscall=258 success=no exit=-13 a0=ffffff9c a1=556f00247800 a2=1ed a3=0 items=0 ppid=1 pid=755 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="(emd-oomd)" exe="/usr/lib/systemd/systemd-executor" subj=system_u:system_r:init_t:s0 key=(null)
Dec 22 13:44:04 localhost audit: PROCTITLE proctitle="(emd-oomd)"
Dec 22 13:44:04 localhost systemd[1]: systemd-oomd.service: Main process exited, code=exited, status=226/NAMESPACE
Dec 22 13:44:04 localhost systemd[1]: systemd-oomd.service: Failed with result 'exit-code'.
Dec 22 13:44:04 localhost systemd[1]: Failed to start systemd-oomd.service - Userspace Out-Of-Memory (OOM) Killer.
Dec 22 13:44:04 localhost audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-oomd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
Dec 22 13:44:05 localhost systemd[1]: systemd-resolved.service: Start request repeated too quickly.
Dec 22 13:44:05 localhost systemd[1]: systemd-resolved.service: Failed with result 'exit-code'.
Dec 22 13:44:05 localhost systemd[1]: Failed to start systemd-resolved.service - Network Name Resolution.
Dec 22 13:44:05 localhost systemd[1]: systemd-oomd.service: Scheduled restart job, restart counter is at 2.
Dec 22 13:44:05 localhost systemd[1]: Starting systemd-oomd.service - Userspace Out-Of-Memory (OOM) Killer...
Dec 22 13:44:05 localhost audit[778]: AVC avc:  denied  { add_name } for  pid=778 comm="(emd-oomd)" name="tmp" scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:unlabeled_t:s0 tclass=dir permissive=0
Dec 22 13:44:05 localhost audit[778]: SYSCALL arch=c000003e syscall=258 success=no exit=-13 a0=ffffff9c a1=5581c1876800 a2=1ed a3=0 items=0 ppid=1 pid=778 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="(emd-oomd)" exe="/usr/lib/systemd/systemd-executor" subj=system_u:system_r:init_t:s0 key=(null)
Dec 22 13:44:05 localhost audit: PROCTITLE proctitle="(emd-oomd)"
Dec 22 13:44:05 localhost (emd-oomd)[778]: Failed to create destination mount point node '/run/systemd/mount-rootfs/var/tmp', ignoring: Permission denied
Dec 22 13:44:05 localhost (emd-oomd)[778]: Failed to mount /run/systemd/unit-private-tmp/var-tmp to /run/systemd/mount-rootfs/var/tmp: No such file or directory
Dec 22 13:44:05 localhost (emd-oomd)[778]: systemd-oomd.service: Failed to set up mount namespacing: /var/tmp: No such file or directory
Dec 22 13:44:05 localhost (emd-oomd)[778]: systemd-oomd.service: Failed at step NAMESPACE spawning /usr/lib/systemd/systemd-oomd: No such file or directory
Dec 22 13:44:05 localhost systemd[1]: systemd-oomd.service: Main process exited, code=exited, status=226/NAMESPACE
Dec 22 13:44:05 localhost systemd[1]: systemd-oomd.service: Failed with result 'exit-code'.
Dec 22 13:44:05 localhost systemd[1]: Failed to start systemd-oomd.service - Userspace Out-Of-Memory (OOM) Killer.
Dec 22 13:44:05 localhost audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-oomd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
Dec 22 13:44:05 localhost systemd[1]: systemd-oomd.service: Scheduled restart job, restart counter is at 3.
Dec 22 13:44:05 localhost systemd[1]: Starting systemd-oomd.service - Userspace Out-Of-Memory (OOM) Killer...
Dec 22 13:44:05 localhost audit[786]: AVC avc:  denied  { add_name } for  pid=786 comm="(emd-oomd)" name="tmp" scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:unlabeled_t:s0 tclass=dir permissive=0
Dec 22 13:44:05 localhost audit[786]: SYSCALL arch=c000003e syscall=258 success=no exit=-13 a0=ffffff9c a1=55da04cb9800 a2=1ed a3=0 items=0 ppid=1 pid=786 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="(emd-oomd)" exe="/usr/lib/systemd/systemd-executor" subj=system_u:system_r:init_t:s0 key=(null)
Dec 22 13:44:05 localhost audit: PROCTITLE proctitle="(emd-oomd)"
Dec 22 13:44:05 localhost (emd-oomd)[786]: Failed to create destination mount point node '/run/systemd/mount-rootfs/var/tmp', ignoring: Permission denied
Dec 22 13:44:05 localhost (emd-oomd)[786]: Failed to mount /run/systemd/unit-private-tmp/var-tmp to /run/systemd/mount-rootfs/var/tmp: No such file or directory
Dec 22 13:44:05 localhost (emd-oomd)[786]: systemd-oomd.service: Failed to set up mount namespacing: /var/tmp: No such file or directory
Dec 22 13:44:05 localhost (emd-oomd)[786]: systemd-oomd.service: Failed at step NAMESPACE spawning /usr/lib/systemd/systemd-oomd: No such file or directory
Dec 22 13:44:05 localhost systemd[1]: systemd-oomd.service: Main process exited, code=exited, status=226/NAMESPACE
Dec 22 13:44:05 localhost systemd[1]: systemd-oomd.service: Failed with result 'exit-code'.
Dec 22 13:44:05 localhost systemd[1]: Failed to start systemd-oomd.service - Userspace Out-Of-Memory (OOM) Killer.
Dec 22 13:44:05 localhost audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-oomd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
Dec 22 13:44:05 localhost systemd[1]: Mounting var.mount - /var...
Dec 22 13:44:05 localhost systemd[1]: systemd-oomd.service: Scheduled restart job, restart counter is at 4.
Dec 22 13:44:05 localhost systemd[1]: Starting systemd-oomd.service - Userspace Out-Of-Memory (OOM) Killer...
Dec 22 13:44:05 localhost systemd[1]: Mounted var.mount - /var.
Dec 22 13:44:05 localhost audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-oomd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Dec 22 13:44:05 localhost systemd[1]: Started systemd-oomd.service - Userspace Out-Of-Memory (OOM) Killer.
Dec 22 13:44:06 localhost NetworkManager[847]: <info>  [1734875046.0028] dns-mgr: init: dns=systemd-resolved rc-manager=unmanaged (auto), plugin=systemd-resolved
Dec 22 13:44:06 localhost.localdomain systemd[1]: systemd-resolved.service: Start request repeated too quickly.
Dec 22 13:44:06 localhost.localdomain systemd[1]: systemd-resolved.service: Failed with result 'exit-code'.
Dec 22 13:44:06 localhost.localdomain systemd[1]: Failed to start systemd-resolved.service - Network Name Resolution.


(Logs are filtered with Fail|oomd|resolved|var\.)


Note how systemd-oomd bareley wins the race with its 5th restart attempt being scheduled right after var.mount is finished;
whereas systemd-resolved.service is a tiny bit too slow and all of its 5 restart attempts fail.

I'm thus updating the reproducibility:

Reproducible: always

(at least in fast VMs)

Comment 2 Georg Sauthoff 2024-12-22 14:08:12 UTC

FWIW, https://openqa.fedoraproject.org/nightlies.html also lists failures for Fedora-Cloud-Base-Generic-Rawhide-20241222, but _not_ for the 'Everything boot' variant.

cf.
https://openqa.fedoraproject.org/tests/3104635
https://openqa.fedoraproject.org/tests/3104638
https://openqa.fedoraproject.org/tests/3104640
https://openqa.fedoraproject.org/tests/3104641
https://openqa.fedoraproject.org/tests/3104643

Comment 3 Martin Pitt 2025-01-07 10:25:03 UTC

We also see this in Cockpit's CI: https://github.com/cockpit-project/bots/issues/7246

Simple standalone reproducer:

curl -o fedora.qcow2 -L https://download.fedoraproject.org/pub/fedora/linux/development/rawhide/Cloud/x86_64/images/Fedora-Cloud-Base-Generic-Rawhide-20250106.n.0.x86_64.qcow2
# nothing fancy, just admin:foobar and root:foobar
curl -L -O https://github.com/cockpit-project/bots/raw/main/machine/cloud-init.iso
qemu-system-x86_64 -cpu host -enable-kvm -nographic -m 2048 -drive file=fedora.qcow2,if=virtio -snapshot -cdrom cloud-init.iso

Then log in as root:foobar. You'll see

Failed Units: 3
  systemd-oomd.service
  systemd-resolved.service
  systemd-oomd.socket

and DNS resolution is broken, e.g. `dnf install` fails.

Comment 4 Martin Pitt 2025-01-11 04:12:28 UTC

This has broken our testing of rawhide for over two weeks now, so time for a hack. Perhaps it's useful for anyone else deploying rawhide out there:

  mkdir -p /etc/systemd/system/systemd-resolved.service.d
  printf '[Service]\nRestartSec=1s\n' > /etc/systemd/system/systemd-resolved.service.d/restart-wait.conf
  systemctl daemon-reload
  systemctl reset-failed systemd-resolved
  systemctl start systemd-resolved

Comment 5 Zbigniew Jędrzejewski-Szmek 2025-01-21 14:52:14 UTC

The change to use PrivateTmp=disconnected was reverted because of #2334015.
So since systemd-257.2-4.fc42 this issue should not be visible.
In #2334015 the bug was understood to be about the selinux policy. But it's
possible that there are other problems with PrivateTmp=disconnected.
I think we should wait for the selinux policy to be updated and then see
if there still are problems.

Comment 6 Michal Sekletar 2025-02-05 19:16:58 UTC

So after couple hours of debugging and chasing my own tail I couldn't believe my eyes. There are directories in root partition of Fedora Cloud qcow2, specifically "home" and "var" that are labeled with "unlabeled_t". That is obviously wrong and PrivateTmp=disconnected just revealed this bug, but because PrivateTmp=disconnected is a new feature I was suspecting bug in its implementation.

# curl -O https://kojipkgs.fedoraproject.org/compose/rawhide/latest-Fedora-Rawhide/compose/Cloud/x86_64/images/Fedora-Cloud-Base-Generic-Rawhide-[root@vm-10-0-184-14 # mkdir /tmp/cloud-image
# qemu-nbd --connect /dev/nbd0 Fedora-Cloud-Base-Generic-Rawhide-20250204.n.0.x86_64.qcow2
# partprobe /dev/nbd0
# mount /dev/nbd0p4 /tmp/cloud-image/
# ls -lZ /tmp/cloud-image/root/
total 24
dr-xr-xr-x. 1 root root system_u:object_r:mnt_t:s0             0 Jan 15 19:00 afs
lrwxrwxrwx. 1 root root system_u:object_r:bin_t:s0             7 Jan 15 19:00 bin -> usr/bin
dr-xr-xr-x. 1 root root system_u:object_r:boot_t:s0            0 Feb  4 01:30 boot
-rw-rw-r--. 1 root root system_u:object_r:etc_runtime_t:s0   142 Feb  4 01:30 config.bootoptions
-rw-rw-r--. 1 root root system_u:object_r:etc_runtime_t:s0    71 Feb  4 01:29 config.partids
drwxrwxr-x. 1 root root system_u:object_r:mock_var_lib_t:s0   60 Feb  4 01:29 dev
drwxr-xr-x. 1 root root system_u:object_r:etc_t:s0          2472 Feb  4 01:29 etc
drwxrwxr-x. 1 root root system_u:object_r:default_t:s0        10 Feb  4 01:30 grub2
drwxrwxr-x. 1 root root system_u:object_r:unlabeled_t:s0       0 Feb  4 01:29 home
lrwxrwxrwx. 1 root root system_u:object_r:lib_t:s0             7 Jan 15 19:00 lib -> usr/lib
lrwxrwxrwx. 1 root root system_u:object_r:lib_t:s0             9 Jan 15 19:00 lib64 -> usr/lib64
drwxr-xr-x. 1 root root system_u:object_r:mnt_t:s0             0 Jan 15 19:00 media
drwxr-xr-x. 1 root root system_u:object_r:mnt_t:s0             0 Jan 15 19:00 mnt
drwxr-xr-x. 1 root root system_u:object_r:usr_t:s0             0 Jan 15 19:00 opt
drwxrwxr-x. 1 root root system_u:object_r:mock_var_lib_t:s0    0 Feb  4 01:24 proc
dr-xr-x---. 1 root root system_u:object_r:admin_home_t:s0     98 Feb  4 01:28 root
drwxr-xr-x. 1 root root system_u:object_r:var_run_t:s0        28 Feb  4 01:30 run
lrwxrwxrwx. 1 root root system_u:object_r:bin_t:s0             8 Jan 15 19:00 sbin -> usr/sbin
drwxr-xr-x. 1 root root system_u:object_r:var_t:s0             0 Jan 15 19:00 srv
drwxrwxr-x. 1 root root system_u:object_r:mock_var_lib_t:s0    0 Feb  4 01:24 sys
drwxrwxrwt. 1 root root system_u:object_r:tmp_t:s0             0 Feb  4 01:30 tmp
drwxr-xr-x. 1 root root system_u:object_r:usr_t:s0           100 Feb  4 01:25 usr
drwxrwxr-x. 1 root root system_u:object_r:unlabeled_t:s0       0 Feb  4 01:29 var

Comment 7 Aoife Moloney 2025-02-26 13:20:28 UTC

This bug appears to have been reported against 'rawhide' during the Fedora Linux 42 development cycle.
Changing version to 42.

Comment 8 Michal Sekletar 2025-04-24 10:58:10 UTC

I see that latest Rawhide cloud image is still mislabeled.

Comment 9 Adam Williamson 2025-04-24 15:54:51 UTC

I would've thought Neal would be the best person to ask here, since Cloud images are now built with Kiwi.

Comment 10 Neal Gompa 2025-04-24 21:31:30 UTC

Sigh. I know why. We label the filesystem before we sync to the final disk setup, which means that the subvolume mount directories themselves are unlabeled.

Can someone please file a bug upstream about this?

Comment 11 Neal Gompa 2025-04-25 11:15:14 UTC

Marcus made a fix: https://github.com/OSInside/kiwi/pull/2785

Comment 12 Fedora Update System 2025-04-29 10:36:05 UTC

FEDORA-2025-b9ae42c8d7 (kiwi-10.2.18-1.fc40) has been submitted as an update to Fedora 40.
https://bodhi.fedoraproject.org/updates/FEDORA-2025-b9ae42c8d7

Comment 13 Fedora Update System 2025-04-29 10:36:17 UTC

FEDORA-EPEL-2025-abc2389dd4 (kiwi-10.2.18-1.el9) has been submitted as an update to Fedora EPEL 9.
https://bodhi.fedoraproject.org/updates/FEDORA-EPEL-2025-abc2389dd4

Comment 14 Fedora Update System 2025-04-29 10:36:53 UTC

FEDORA-EPEL-2025-1516ba47ea (kiwi-10.2.18-1.el10_1) has been submitted as an update to Fedora EPEL 10.1.
https://bodhi.fedoraproject.org/updates/FEDORA-EPEL-2025-1516ba47ea

Comment 15 Fedora Update System 2025-04-29 10:37:17 UTC

FEDORA-EPEL-2025-a6bd816644 (kiwi-10.2.17-1.el10_0) has been submitted as an update to Fedora EPEL 10.0.
https://bodhi.fedoraproject.org/updates/FEDORA-EPEL-2025-a6bd816644

Comment 16 Fedora Update System 2025-04-29 10:37:54 UTC

FEDORA-2025-caba97efbd (kiwi-10.2.18-1.fc42) has been submitted as an update to Fedora 42.
https://bodhi.fedoraproject.org/updates/FEDORA-2025-caba97efbd

Comment 17 Fedora Update System 2025-04-29 10:38:53 UTC

FEDORA-2025-7cf125b833 (kiwi-10.2.18-1.fc41) has been submitted as an update to Fedora 41.
https://bodhi.fedoraproject.org/updates/FEDORA-2025-7cf125b833

Comment 18 Fedora Update System 2025-04-29 20:39:55 UTC

FEDORA-2025-caba97efbd (kiwi-10.2.18-1.fc42) has been pushed to the Fedora 42 stable repository.
If problem still persists, please make note of it in this bug report.

Comment 19 Fedora Update System 2025-04-30 01:38:10 UTC

FEDORA-2025-7cf125b833 (kiwi-10.2.18-1.fc41) has been pushed to the Fedora 41 stable repository.
If problem still persists, please make note of it in this bug report.

Comment 20 Fedora Update System 2025-04-30 01:56:42 UTC

FEDORA-EPEL-2025-1516ba47ea (kiwi-10.2.18-1.el10_1) has been pushed to the Fedora EPEL 10.1 stable repository.
If problem still persists, please make note of it in this bug report.

Comment 21 Fedora Update System 2025-04-30 02:00:50 UTC

FEDORA-2025-b9ae42c8d7 (kiwi-10.2.18-1.fc40) has been pushed to the Fedora 40 stable repository.
If problem still persists, please make note of it in this bug report.

Comment 22 Fedora Update System 2025-04-30 02:13:30 UTC

FEDORA-EPEL-2025-a6bd816644 (kiwi-10.2.18-1.el10_0) has been pushed to the Fedora EPEL 10.0 stable repository.
If problem still persists, please make note of it in this bug report.

Comment 23 Fedora Update System 2025-04-30 02:29:48 UTC

FEDORA-EPEL-2025-abc2389dd4 (kiwi-10.2.18-1.el9) has been pushed to the Fedora EPEL 9 stable repository.
If problem still persists, please make note of it in this bug report.