Note: This is a public test instance of Red Hat Bugzilla. The data contained within is a snapshot of the live data so any changes you make will not be reflected in the production Bugzilla. Email is disabled so feel free to test any aspect of the site that you want. File any problems you find or give feedback at bugzilla.redhat.com.
Bug 1948042 - systemd-networkd fails at system start
Summary: systemd-networkd fails at system start
Keywords:
Status: RELEASE_PENDING
Alias: None
Product: Fedora
Classification: Fedora
Component: dbus-broker
Version: 34
Hardware: x86_64
OS: Unspecified
unspecified
high
Target Milestone: ---
Assignee: David Rheinsberg
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2021-04-09 20:13 UTC by Andrew G. Dunn
Modified: 2021-06-24 09:51 UTC (History)
22 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed:
Type: Bug
Embargoed:

Attachments (Terms of Use)

Description Andrew G. Dunn 2021-04-09 20:13:50 UTC 
Description of problem: At system startup systemd-networkd fails to start. After startup you can restart systemd-networkd and it functions properly.

This manifested in VM and I thought it was an oddity, I've not reproduced it consistently on all of my F34 installs. All installs are x86_64, but networking varies between intel and {nvidia,mellanox}, as well as AMD/EPYC and Intel.

Asked in #systemd on freenode and others confirmed to have seen the same behavior.

Another oddity, that may be related, is that systemd-timesyncd also fails to start in a similar fashion at boot but can be restarted and functions properly.


Version-Release number of selected component (if applicable): 248


How reproducible: consistent across multiple installs


Steps to Reproduce:
1. Install Fedora 34 from Beta media
2. systemctl disable NetworkManager
3. write configurations for networkd (/etc/systemd/networkd)
4. systemctl enable systemd-networkd
5. reboot

Actual results: systemd-networkd fails to start on system boot


Expected results: systemd-networkd succeeds to start on system boot


Additional info: 

Talking on IRC:

 - sarnold: given that the error message about permission denied happens the same moment as the inotify watch denial, that seems pretty plausible as a cause

From `journalctl -b`

Apr 09 14:52:58 vault systemd[1]: Starting Network Service...
Apr 09 14:52:58 vault systemd[1]: Starting Load Kernel Module configfs...
Apr 09 14:52:58 vault systemd[1]: modprobe: Deactivated successfully.
Apr 09 14:52:58 vault systemd[1]: Finished Load Kernel Module configfs.
Apr 09 14:52:58 vault audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=modprobe@configfs comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 09 14:52:58 vault audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=modprobe@configfs comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 09 14:52:58 vault audit[2180]: AVC avc:  denied  { watch } for  pid=2180 comm="systemd-network" path="/" dev="dm-0" ino=128 scontext=system_u:system_r:systemd_networkd_t:s0 tcontext=system_u:object_r:root_t:s0 tclass=dir permissive=0
Apr 09 14:52:58 vault audit[2180]: SYSCALL arch=c000003e syscall=254 success=no exit=-13 a0=e a1=7f4d09eafd42 a2=180 a3=7fffd18cdb54 items=0 ppid=1 pid=2180 auid=4294967295 uid=192 gid=192 euid=192 suid=192 fsuid=192 egid=192 sgid=192 fsg>
Apr 09 14:52:58 vault audit: PROCTITLE proctitle="/usr/lib/systemd/systemd-networkd"
Apr 09 14:52:58 vault systemd-networkd[2180]: Failed to connect to bus: Permission denied
Apr 09 14:52:58 vault systemd-networkd[2180]: Could not connect to bus: Permission denied
Apr 09 14:52:58 vault systemd[1]: systemd-networkd.service: Main process exited, code=exited, status=1/FAILURE
Apr 09 14:52:58 vault systemd[1]: systemd-networkd.service: Failed with result 'exit-code'.
Apr 09 14:52:58 vault systemd[1]: Failed to start Network Service.
Apr 09 14:52:58 vault systemd[1]: Dependency failed for Wait for Network to be Configured.
Apr 09 14:52:58 vault audit: BPF prog-id=32 op=UNLOAD
Apr 09 14:52:58 vault systemd[1]: systemd-networkd-wait-online.service: Job systemd-networkd-wait-online.service/start failed with result 'dependency'.
Apr 09 14:52:58 vault audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-networkd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
Apr 09 14:52:58 vault systemd[1]: systemd-networkd.service: Scheduled restart job, restart counter is at 1.
Apr 09 14:52:58 vault systemd[1]: Stopped Network Service.
Apr 09 14:52:58 vault audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-networkd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 09 14:52:58 vault audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-networkd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 09 14:52:58 vault audit: BPF prog-id=33 op=LOAD
Apr 09 14:52:58 vault systemd[1]: Starting Network Service...
Apr 09 14:52:59 vault audit[2198]: AVC avc:  denied  { watch } for  pid=2198 comm="systemd-network" path="/" dev="dm-0" ino=128 scontext=system_u:system_r:systemd_networkd_t:s0 tcontext=system_u:object_r:root_t:s0 tclass=dir permissive=0
Apr 09 14:52:59 vault audit[2198]: SYSCALL arch=c000003e syscall=254 success=no exit=-13 a0=e a1=7f2a390e2d42 a2=180 a3=7fff11742044 items=0 ppid=1 pid=2198 auid=4294967295 uid=192 gid=192 euid=192 suid=192 fsuid=192 egid=192 sgid=192 fsg>
Apr 09 14:52:59 vault audit: PROCTITLE proctitle="/usr/lib/systemd/systemd-networkd"
Apr 09 14:52:59 vault systemd-networkd[2198]: Failed to connect to bus: Permission denied
Apr 09 14:52:59 vault systemd-networkd[2198]: Could not connect to bus: Permission denied
Apr 09 14:52:59 vault systemd[1]: systemd-networkd.service: Main process exited, code=exited, status=1/FAILURE
Apr 09 14:52:59 vault systemd[1]: systemd-networkd.service: Failed with result 'exit-code'.
Apr 09 14:52:59 vault systemd[1]: Failed to start Network Service.
Apr 09 14:52:59 vault audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-networkd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
Apr 09 14:52:59 vault systemd[1]: systemd-networkd.service: Scheduled restart job, restart counter is at 2.
Apr 09 14:52:59 vault systemd[1]: Stopped Network Service.
Apr 09 14:52:59 vault audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-networkd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 09 14:52:59 vault audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-networkd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 09 14:52:59 vault audit: BPF prog-id=34 op=LOAD
Apr 09 14:52:59 vault systemd[1]: Starting Network Service...
Apr 09 14:52:59 vault audit: BPF prog-id=33 op=UNLOAD
Apr 09 14:52:59 vault audit[2206]: AVC avc:  denied  { watch } for  pid=2206 comm="systemd-network" path="/" dev="dm-0" ino=128 scontext=system_u:system_r:systemd_networkd_t:s0 tcontext=system_u:object_r:root_t:s0 tclass=dir permissive=0
Apr 09 14:52:59 vault audit[2206]: SYSCALL arch=c000003e syscall=254 success=no exit=-13 a0=e a1=7fad3152fd42 a2=180 a3=7ffede74ec24 items=0 ppid=1 pid=2206 auid=4294967295 uid=192 gid=192 euid=192 suid=192 fsuid=192 egid=192 sgid=192 fsg>
Apr 09 14:52:59 vault audit: PROCTITLE proctitle="/usr/lib/systemd/systemd-networkd"
Apr 09 14:52:59 vault systemd-networkd[2206]: Failed to connect to bus: Permission denied
Apr 09 14:52:59 vault systemd-networkd[2206]: Could not connect to bus: Permission denied
Apr 09 14:52:59 vault systemd[1]: systemd-networkd.service: Main process exited, code=exited, status=1/FAILURE
Apr 09 14:52:59 vault systemd[1]: systemd-networkd.service: Failed with result 'exit-code'.
Apr 09 14:52:59 vault systemd[1]: Failed to start Network Service.
Apr 09 14:52:59 vault audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-networkd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
Apr 09 14:52:59 vault systemd[1]: systemd-networkd.service: Scheduled restart job, restart counter is at 3.
Apr 09 14:52:59 vault systemd[1]: Stopped Network Service.
Apr 09 14:52:59 vault audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-networkd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 09 14:52:59 vault audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-networkd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 09 14:52:59 vault audit: BPF prog-id=34 op=UNLOAD
Apr 09 14:52:59 vault audit: BPF prog-id=35 op=LOAD
Apr 09 14:52:59 vault systemd[1]: Starting Network Service...
Apr 09 14:52:59 vault audit[2208]: AVC avc:  denied  { watch } for  pid=2208 comm="systemd-network" path="/" dev="dm-0" ino=128 scontext=system_u:system_r:systemd_networkd_t:s0 tcontext=system_u:object_r:root_t:s0 tclass=dir permissive=0
Apr 09 14:52:59 vault audit[2208]: SYSCALL arch=c000003e syscall=254 success=no exit=-13 a0=e a1=7f6940be4d42 a2=180 a3=7ffebd8b2c64 items=0 ppid=1 pid=2208 auid=4294967295 uid=192 gid=192 euid=192 suid=192 fsuid=192 egid=192 sgid=192 fsg>
Apr 09 14:52:59 vault audit: PROCTITLE proctitle="/usr/lib/systemd/systemd-networkd"
Apr 09 14:52:59 vault systemd-networkd[2208]: Failed to connect to bus: Permission denied
Apr 09 14:52:59 vault systemd-networkd[2208]: Could not connect to bus: Permission denied
Apr 09 14:52:59 vault systemd[1]: systemd-networkd.service: Main process exited, code=exited, status=1/FAILURE
Apr 09 14:52:59 vault systemd[1]: systemd-networkd.service: Failed with result 'exit-code'.
Apr 09 14:52:59 vault systemd[1]: Failed to start Network Service.
Apr 09 14:52:59 vault audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-networkd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
Apr 09 14:52:59 vault systemd[1]: systemd-networkd.service: Scheduled restart job, restart counter is at 4.
Apr 09 14:52:59 vault systemd[1]: Stopped Network Service.
Apr 09 14:52:59 vault audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-networkd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 09 14:52:59 vault audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-networkd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 09 14:52:59 vault audit: BPF prog-id=35 op=UNLOAD
Apr 09 14:52:59 vault audit: BPF prog-id=36 op=LOAD
Apr 09 14:52:59 vault systemd[1]: Starting Network Service...
Apr 09 14:52:59 vault kernel: acpi_cpufreq: overriding BIOS provided _PSD data
Apr 09 14:52:59 vault audit[2213]: AVC avc:  denied  { watch } for  pid=2213 comm="systemd-network" path="/" dev="dm-0" ino=128 scontext=system_u:system_r:systemd_networkd_t:s0 tcontext=system_u:object_r:root_t:s0 tclass=dir permissive=0
Apr 09 14:52:59 vault audit[2213]: SYSCALL arch=c000003e syscall=254 success=no exit=-13 a0=e a1=7fae78299d42 a2=180 a3=7ffcdb9990f4 items=0 ppid=1 pid=2213 auid=4294967295 uid=192 gid=192 euid=192 suid=192 fsuid=192 egid=192 sgid=192 fsg>
Apr 09 14:52:59 vault audit: PROCTITLE proctitle="/usr/lib/systemd/systemd-networkd"
Apr 09 14:52:59 vault systemd-networkd[2213]: Failed to connect to bus: Permission denied
Apr 09 14:52:59 vault systemd-networkd[2213]: Could not connect to bus: Permission denied
Apr 09 14:52:59 vault systemd[1]: systemd-networkd.service: Main process exited, code=exited, status=1/FAILURE
Apr 09 14:52:59 vault systemd[1]: systemd-networkd.service: Failed with result 'exit-code'.
Apr 09 14:52:59 vault systemd[1]: Failed to start Network Service.
Apr 09 14:52:59 vault audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-networkd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
Apr 09 14:52:59 vault systemd[1]: systemd-networkd.service: Scheduled restart job, restart counter is at 5.
Apr 09 14:52:59 vault systemd[1]: Stopped Network Service.
Apr 09 14:52:59 vault audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-networkd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 09 14:52:59 vault audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-networkd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 09 14:52:59 vault systemd[1]: systemd-networkd.service: Start request repeated too quickly.
Apr 09 14:52:59 vault systemd[1]: systemd-networkd.service: Failed with result 'exit-code'.
Apr 09 14:52:59 vault systemd[1]: Failed to start Network Service.
Apr 09 14:52:59 vault systemd[1]: systemd-networkd.socket: Failed with result 'service-start-limit-hit'.
Apr 09 14:52:59 vault systemd[1]: Finished Coldplug All udev Devices.
Comment 1 Göran Uddeborg 2021-04-11 17:31:36 UTC 
I have started to see the same behaviour on one real hardware machine upgraded to the F34 kernel and systemd. My understanding is this happens because a race condition where systemd-networkd on this machine tries to start before dbus is available. (Other machines also updated don't have the problem, but they have slightly different services running which might tilt things the other way.)

I created a service drop in file /etc/systemd/system/systemd-networkd.service.d/after-dbus.conf 

    [Unit]
    After=dbus.socket

With this it seems my machine can reliably boot again.

The AVCs also disappear with this extra configuration. I'm guessing systemd-networkd tries to take some other code path when dbus isn't available, something which SELinux won't allow. But that is just a guess.
Comment 2 Andrew G. Dunn 2021-04-12 01:01:20 UTC 
Thanks Göran, can confirm this workaround addresses my issues (for both systemd-networkd and systemd-timesyncd)
Comment 3 Leif Liddy 2021-05-01 03:23:51 UTC 
Thanks Göran, your workaround works great!
Comment 4 Gerhard Wiesinger 2021-05-02 17:01:05 UTC 
Thanks Göran, can confirm your workaround works great!
Comment 5 Zbigniew Jędrzejewski-Szmek 2021-05-07 13:59:47 UTC 
Possibly related:https://github.com/systemd/systemd/issues/19212.
Comment 6 Dominik 'Rathann' Mierzejewski 2021-05-17 08:53:01 UTC 
Same here, but without AVCs. Issue started after upgrading my VM to F34.
Comment 7 Zbigniew Jędrzejewski-Szmek 2021-06-21 16:41:07 UTC 
There are two ways to fix this: in dbus-broker, create the dbus socket earlier.
This is implemented by https://github.com/bus1/dbus-broker/commit/28af5ac996c94922fc49660e0efa955f57575187.
I'll reassign this to dbus-broker to wait for that patch.

The second way is in selinux policy, allow systemd-networkd to watch for the socket to appear.
This is the same as https://bugzilla.redhat.com/show_bug.cgi?id=1970359. I'll add a comment
there to include systemd-networkd in the change too.
Comment 8 David Rheinsberg 2021-06-24 09:51:13 UTC 
dbus-broker-29-1 will include this fix. Already available in rawhide, updates for F34 pending.
Comment 9 David Rheinsberg 2021-06-24 09:51:54 UTC 
Thanks a lot for the report and the detailed comments on Github! If this does not suffice, let me know!
Note You need to log in before you can comment on or make changes to this bug.