[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