[systemd-devel] systemd-networkd not discovering all devices at bootup, and thus no network is configured

Lennart Poettering lennart at poettering.net
Wed Feb 11 10:39:20 PST 2015


On Wed, 04.02.15 21:58, Keller, Jacob E (jacob.e.keller at intel.com) wrote:

> Hi again,
> 
> On Tue, 2015-02-03 at 19:00 +0000, Keller, Jacob E wrote:
> > Hey,
> > 
> > I've recently been using systemd-networkd to great success on a few of
> > my machines here. However I ran into an interesting problem on at least
> > 2 machines so far. I've included the output of journal for
> > systemd-networkd with Environment=SYSTEMD_LOG_LEVEL=debug as was
> > suggested on another post. In addition the only network file I have
> > configured is em0.network which contains the following,
> > 
> > $cat /etc/systemd/network/em0.network
> > [Match]
> > Name=em0
> > 
> > [Network]
> > DHCP=Yes
> > 
> > The journalctl for systemd-networkd after bootup is,
> > 
> > -- Logs begin at Mon 2012-12-31 20:02:09 PST, end at Tue 2015-02-03 10:57:09 PST. --
> > Feb 03 10:37:44 jekeller-copperpass systemd-networkd[1055]: timestamp of '/etc/systemd/network' changed
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: br0             : flags change: +MULTICAST +BROADCAST
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: br0             : link 7 added
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: br0             : udev initialized link
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: br0             : saved original MTU: 1500
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: br-geneve0      : flags change: +MULTICAST +BROADCAST
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: br-geneve0      : link 8 added
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: br-geneve0      : udev initialized link
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: br-geneve0      : saved original MTU: 1500
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: Sent message type=method_call sender=n/a destination=org.freedesktop.DBus object=/org/freedesktop/DBus interface=org.freedesktop.DBus member=Hello cookie=1 reply_cookie=0 error=n/a
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: br0             : MAC address: 7e:5e:7c:31:44:4d
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: br-geneve0      : MAC address: b6:ec:a9:4b:e5:42
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: br0             : getting address failed: Device or resource busy
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: br0             : link state is up-to-date
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: br0             : unmanaged
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: Got message type=method_return sender=org.freedesktop.DBus destination=:1.7 object=n/a interface=n/a member=n/a cookie=1 reply_cookie=1 error=n/a
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: Got message type=signal sender=org.freedesktop.DBus destination=:1.7 object=/org/freedesktop/DBus interface=org.freedesktop.DBus member=NameAcquired cookie=2 reply_cookie=0 error=n/a
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: br-geneve0      : link state is up-to-date
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: br-geneve0      : unmanaged
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: rtnl: received address for a nonexistent link (1), ignoring
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: rtnl: received address for a nonexistent link (1), ignoring
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: virbr0          : flags change: +MULTICAST +BROADCAST
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: virbr0          : link 9 added
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: virbr0          : udev initialized link
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: virbr0          : saved original MTU: 1500
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: virbr0          : link state is up-to-date
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: virbr0          : unmanaged
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: rtnl: received address for a nonexistent link (1), ignoring
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: rtnl: received address for a nonexistent link (1), ignoring
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: virbr0-nic      : flags change: +MULTICAST +BROADCAST
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: virbr0-nic      : link 10 added
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: virbr0-nic      : udev initialized link
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: virbr0-nic      : saved original MTU: 1500
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: virbr0-nic      : MAC address: 52:54:00:84:d2:d5
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: virbr0-nic      : link state is up-to-date
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: virbr0-nic      : unmanaged
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: rtnl: received address for a nonexistent link (1), ignoring
> > Feb 03 10:37:45 jekeller-copperpass systemd-networkd[1055]: rtnl: received address for a nonexistent link (1), ignoring
> > Feb 03 10:37:46 jekeller-copperpass systemd-networkd[1055]: virbr0          : MAC address: 52:54:00:84:d2:d5
> > Feb 03 10:37:46 jekeller-copperpass systemd-networkd[1055]: virbr0-nic      : flags change: +UP +LOWER_UP +RUNNING
> > Feb 03 10:37:46 jekeller-copperpass systemd-networkd[1055]: virbr0-nic      : gained carrier
> > Feb 03 10:37:46 jekeller-copperpass systemd-networkd[1055]: virbr0          : added address: 192.168.122.1/24 (valid for ever)
> > Feb 03 10:37:46 jekeller-copperpass systemd-networkd[1055]: virbr0          : flags change: +UP
> > Feb 03 10:37:46 jekeller-copperpass systemd-networkd[1055]: virbr0-nic      : flags change: -UP -LOWER_UP -RUNNING
> > Feb 03 10:37:46 jekeller-copperpass systemd-networkd[1055]: virbr0-nic      : lost carrier
> > Feb 03 10:37:46 jekeller-copperpass systemd-networkd[1055]: virbr0-nic      : removing non-existent address: fe80::5054:ff:fe84:d2d5/64 (valid for ever)
> > 
> > Notice that only a bunch of my fake devices, hand made bridges, and such
> > are found during bootup. However, if I manually restart networkd then it
> > finds all the devices,
> > 
> > 
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: timestamp of '/etc/systemd/network' changed
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: virbr0-nic      : flags change: +MULTICAST +BROADCAST
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: virbr0-nic      : link 10 added
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: virbr0-nic      : udev initialized link
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: virbr0-nic      : saved original MTU: 1500
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: virbr0          : flags change: +UP +MULTICAST +BROADCAST
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: virbr0          : link 9 added
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: virbr0          : udev initialized link
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: virbr0          : saved original MTU: 1500
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: br-geneve0      : flags change: +MULTICAST +BROADCAST
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: br-geneve0      : link 8 added
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: br-geneve0      : udev initialized link
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: br-geneve0      : saved original MTU: 1500
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: br0             : flags change: +MULTICAST +BROADCAST
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: br0             : link 7 added
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: br0             : udev initialized link
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: br0             : saved original MTU: 1500
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: ovs-system      : flags change: +MULTICAST +BROADCAST
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: ovs-system      : link 6 added
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: ovs-system      : udev initialized link
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: ovs-system      : saved original MTU: 1500
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: enp4s0f3        : flags change: +MULTICAST +BROADCAST
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: enp4s0f3        : link 5 added
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: enp4s0f3        : udev initialized link
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: enp4s0f3        : saved original MTU: 1500
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: enp4s0f2        : flags change: +MULTICAST +BROADCAST
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: enp4s0f2        : link 4 added
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: enp4s0f2        : udev initialized link
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: enp4s0f2        : saved original MTU: 1500
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: enp4s0f1        : flags change: +MULTICAST +BROADCAST
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: enp4s0f1        : link 3 added
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: enp4s0f1        : udev initialized link
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: enp4s0f1        : saved original MTU: 1500
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: em0             : flags change: +MULTICAST +BROADCAST
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: em0             : link 2 added
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: em0             : udev initialized link
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: em0             : saved original MTU: 1500
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: lo              : flags change: +LOOPBACK +UP +LOWER_UP +RUNNING
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: lo              : link 1 added
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: lo              : udev initialized link
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: lo              : saved original MTU: 0
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: virbr0-nic      : link state is up-to-date
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: virbr0-nic      : unmanaged
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: Sent message type=method_call sender=n/a destination=org.freedesktop.DBus object=/org/freedesktop/DBus interface=org.freedesktop.DBus member=Hello cookie=1 reply_cookie=0 error=n/a
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: virbr0          : getting address failed: Device or resource busy
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: virbr0          : link state is up-to-date
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: virbr0          : unmanaged
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: Got message type=method_return sender=org.freedesktop.DBus destination=:1.71 object=n/a interface=n/a member=n/a cookie=1 reply_cookie=1 error=n/a
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: br-geneve0      : getting address failed: Device or resource busy
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: Got message type=signal sender=org.freedesktop.DBus destination=:1.71 object=/org/freedesktop/DBus interface=org.freedesktop.DBus member=NameAcquired cookie=2 reply_cookie=0 error=n/a
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: br-geneve0      : link state is up-to-date
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: br-geneve0      : unmanaged
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: br0             : getting address failed: Device or resource busy
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: br0             : link state is up-to-date
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: br0             : unmanaged
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: ovs-system      : getting address failed: Device or resource busy
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: ovs-system      : link state is up-to-date
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: ovs-system      : unmanaged
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: enp4s0f3        : getting address failed: Device or resource busy
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: enp4s0f3        : link state is up-to-date
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: enp4s0f3        : unmanaged
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: enp4s0f2        : getting address failed: Device or resource busy
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: enp4s0f2        : link state is up-to-date
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: enp4s0f2        : unmanaged
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: enp4s0f1        : getting address failed: Device or resource busy
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: enp4s0f1        : link state is up-to-date
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: enp4s0f1        : unmanaged
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: em0             : getting address failed: Device or resource busy
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: em0             : link state is up-to-date
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: em0             : found matching network '/etc/systemd/network/em0.network'
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: em0             : bringing link up
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: lo              : getting address failed: Device or resource busy
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: lo              : link state is up-to-date
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: lo              : unmanaged
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: lo              : added address: ::1/128 (valid for ever)
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: virbr0          : added address: 192.168.122.1/24 (valid for ever)
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: lo              : added address: 127.0.0.1/8 (valid for ever)
> > Feb 03 10:51:49 jekeller-copperpass systemd-networkd[2537]: em0             : flags change: +UP
> > Feb 03 10:51:53 jekeller-copperpass systemd-networkd[2537]: em0             : flags change: +LOWER_UP +RUNNING
> > Feb 03 10:51:53 jekeller-copperpass systemd-networkd[2537]: em0             : gained carrier
> > Feb 03 10:51:53 jekeller-copperpass systemd-networkd[2537]: em0             : acquiring DHCPv4 lease
> > Feb 03 10:51:53 jekeller-copperpass systemd-networkd[2537]: DHCP CLIENT (0x3d9e3244): STARTED on ifindex 2
> > Feb 03 10:51:53 jekeller-copperpass systemd-networkd[2537]: em0             : discovering IPv6 routers
> > Feb 03 10:51:53 jekeller-copperpass systemd-networkd[2537]: ICMPv6 CLIENT: Start Router Solicitation
> > Feb 03 10:51:53 jekeller-copperpass systemd-networkd[2537]: ICMPv6 CLIENT: Error sending Router Solicitation
> > Feb 03 10:51:53 jekeller-copperpass systemd-networkd[2537]: DHCP CLIENT (0x3d9e3244): DISCOVER
> > Feb 03 10:51:54 jekeller-copperpass systemd-networkd[2537]: DHCP CLIENT (0x3d9e3244): OFFER
> > Feb 03 10:51:54 jekeller-copperpass systemd-networkd[2537]: DHCP CLIENT (0x3d9e3244): REQUEST (requesting)
> > Feb 03 10:51:54 jekeller-copperpass systemd-networkd[2537]: DHCP CLIENT (0x3d9e3244): ACK
> > Feb 03 10:51:54 jekeller-copperpass systemd-networkd[2537]: DHCP CLIENT (0x3d9e3244): lease expires in 6h 48min 31.142449s
> > Feb 03 10:51:54 jekeller-copperpass systemd-networkd[2537]: DHCP CLIENT (0x3d9e3244): T2 expires in 5h 57min 27.825629s
> > Feb 03 10:51:54 jekeller-copperpass systemd-networkd[2537]: DHCP CLIENT (0x3d9e3244): T1 expires in 3h 24min 17.074622s
> > Feb 03 10:51:54 jekeller-copperpass systemd-networkd[2537]: em0             : DHCPv4 address 192.168.0.217/24 via 192.168.0.1
> > Feb 03 10:51:54 jekeller-copperpass systemd-networkd[2537]: em0             : added address: 192.168.0.217/24 (valid for 6h 48min 34s)
> > Feb 03 10:51:54 jekeller-copperpass systemd-networkd[2537]: em0             : link configured
> > Feb 03 10:51:54 jekeller-copperpass systemd-networkd[2537]: em0             : added address: fe80::21e:67ff:fe9a:c01f/64 (valid for ever)
> > Feb 03 10:51:57 jekeller-copperpass systemd-networkd[2537]: ICMPv6 CLIENT: Sent Router Solicitation
> > Feb 03 10:52:01 jekeller-copperpass systemd-networkd[2537]: ICMPv6 CLIENT: Sent Router Solicitation
> > Feb 03 10:52:05 jekeller-copperpass systemd-networkd[2537]: DHCPv6 CLIENT: Sent SOLICIT
> > Feb 03 10:52:05 jekeller-copperpass systemd-networkd[2537]: DHCPv6 CLIENT: Next retransmission in 1.053130s
> > Feb 03 10:52:06 jekeller-copperpass systemd-networkd[2537]: DHCPv6 CLIENT: Sent SOLICIT
> > Feb 03 10:52:06 jekeller-copperpass systemd-networkd[2537]: DHCPv6 CLIENT: Next retransmission in 2.169218s
> > Feb 03 10:52:08 jekeller-copperpass systemd-networkd[2537]: DHCPv6 CLIENT: Sent SOLICIT
> > Feb 03 10:52:08 jekeller-copperpass systemd-networkd[2537]: DHCPv6 CLIENT: Next retransmission in 4.550442s
> > Feb 03 10:52:13 jekeller-copperpass systemd-networkd[2537]: DHCPv6 CLIENT: Sent SOLICIT
> > Feb 03 10:52:13 jekeller-copperpass systemd-networkd[2537]: DHCPv6 CLIENT: Next retransmission in 9.418559s
> > Feb 03 10:52:22 jekeller-copperpass systemd-networkd[2537]: DHCPv6 CLIENT: Sent SOLICIT
> > Feb 03 10:52:22 jekeller-copperpass systemd-networkd[2537]: DHCPv6 CLIENT: Next retransmission in 19.178444s
> > Feb 03 10:52:42 jekeller-copperpass systemd-networkd[2537]: DHCPv6 CLIENT: Sent SOLICIT
> > Feb 03 10:52:42 jekeller-copperpass systemd-networkd[2537]: DHCPv6 CLIENT: Next retransmission in 36.913006s
> > 
> > Any suggestions as to why networkd doesn't (a) find em0 during bootup,
> > or (b) configure it when it does appear after boot up?
> > 
> > Thanks for all your work, much appreciated.
> > 
> > Regards,
> > Jake
> 
> I actually see the same behavior now again, so the removal of
> biosdevname does not solve this problem! :(
> 
> Is there any more information I can provide?

Hmm, it appears as if networkd completely misses the netlink messages
describing your em0 link.

To debug this it might be worse adding debug log messages to
manager_rtnl_process_link() to see if any rtnl messages announcing the
interface are received by networkd. If no such message arrives there,
then this indicates a kernel issue, otherwise a bug in networkd.

Lennart

-- 
Lennart Poettering, Red Hat


More information about the systemd-devel mailing list