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

Wed Feb 11 14:28:25 PST 2015

On Wed, 2015-02-11 at 21:46 +0100, Lennart Poettering wrote:
> On Wed, 11.02.15 20:36, Keller, Jacob E (jacob.e.keller at intel.com) wrote:
> 
> > > > Yes. I believe that possibly the netlink messages are occurring too
> > > > early before networkd has started. Thus, when I restart the service
> > > > after startup it works fine.
> > > 
> > > Well, the first thing after subscribing to links coming/going that
> > > networkd does is query the kernel for the list of devices it has. This
> > > means that it should always get all links, regardless when it is started.
> > 
> > What about network device renames? Devices are renamed after they
> > appear. Is it also possible that networkd is started too early and thus
> > the devices haven't actually appeared yet? But.. then it should get the
> > message once it does appear? (assuming here that it continues listening
> > to rtnl messages about links)
> 
> networkd should get all netlink msgs about all of this just fine, and
> be able to track renames and everything.
> 
> > How difficult would it be to create an RPM? 
> 
> Well, you can get the spec file from fedpkg and then use it on a
> tarball from systemd git made with "make dist". But you probably need
> to make a number of updates to the .spec file. Unless you are an RPM
> guru I wouldn't bother.
> 
> Lennart
> 

Ok. I got the upstream systemd installed. Now I get a very different
behavior, which I am unsure of.

I cut off the last message as it repeated some odd ten thousand times or
so... Presumably retry/failing...

At any rate, it appears possible that some configuration is wrong, or
similar? Any suggestions/thoughts now?

Regards,
Jake

-- Logs begin at Mon 2012-12-31 20:02:09 PST, end at Wed 2015-02-11 14:23:01 PST. --
Feb 11 14:21:46 jekeller-copperpass systemd[1]: Starting Network Service...
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: 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 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: Got message type=method_return sender=org.freedesktop.DBus destination=:1.1 object=n/a interface=n/a member=n/a cookie=1 reply_cookie=1 error=n/a
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: Sent message type=method_call sender=n/a destination=org.freedesktop.DBus object=/org/freedesktop/DBus interface=org.freedesktop.DBus member=AddMatch cookie=2 reply_cookie=0 error=n/a
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: Sent message type=method_call sender=n/a destination=org.freedesktop.DBus object=/org/freedesktop/DBus interface=org.freedesktop.DBus member=RequestName cookie=3 reply_cookie=0 error=n/a
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: timestamp of '/etc/systemd/network' changed
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: timestamp of '/usr/lib/systemd/network' changed
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f3        : flags change: +MULTICAST +BROADCAST
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f3        : link 7 added
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: device 0x7fef36c2d6d0 has devpath '/devices/pci0000:00/0000:00:01.1/0000:04:00.3/net/enp4s0f3'
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: device 0x7fef36c2d6d0 filled with db file data
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f3        : udev initialized link
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f3        : saved original MTU: 1500
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f2        : flags change: +MULTICAST +BROADCAST
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f2        : link 6 added
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: device 0x7fef36c2eba0 has devpath '/devices/pci0000:00/0000:00:01.1/0000:04:00.2/net/enp4s0f2'
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: device 0x7fef36c2eba0 filled with db file data
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f2        : udev initialized link
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f2        : saved original MTU: 1500
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f1        : flags change: +MULTICAST +BROADCAST
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f1        : link 5 added
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: device 0x7fef36c2ffe0 has devpath '/devices/pci0000:00/0000:00:01.1/0000:04:00.1/net/enp4s0f1'
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: device 0x7fef36c2ffe0 filled with db file data
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f1        : udev initialized link
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f1        : saved original MTU: 1500
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f0        : flags change: +MULTICAST +BROADCAST
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f0        : link 4 added
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: device 0x7fef36c31440 has devpath '/devices/pci0000:00/0000:00:01.1/0000:04:00.0/net/enp4s0f0'
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: device 0x7fef36c31440 filled with db file data
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f0        : udev initialized link
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f0        : saved original MTU: 1500
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: ens9            : flags change: +MULTICAST +BROADCAST
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: ens9            : link 3 added
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: device 0x7fef36c32860 has devpath '/devices/pci0000:00/0000:00:02.0/0000:06:00.0/0000:07:09.0/0000:09:00.0/net/ens9'
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: device 0x7fef36c32860 filled with db file data
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: ens9            : udev initialized link
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: ens9            : saved original MTU: 1500
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: ens8            : flags change: +MULTICAST +BROADCAST
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: ens8            : link 2 added
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: device 0x7fef36c33c30 has devpath '/devices/pci0000:00/0000:00:02.0/0000:06:00.0/0000:07:08.0/0000:08:00.0/net/ens8'
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: device 0x7fef36c33c30 filled with db file data
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: ens8            : udev initialized link
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: ens8            : saved original MTU: 1500
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: lo              : flags change: +LOOPBACK +UP +LOWER_UP +RUNNING
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: Sent message type=signal sender=n/a destination=n/a object=/org/freedesktop/network1/link/_31 interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=4 reply_cookie=0 error=n/a
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: lo              : link 1 added
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: device 0x7fef36c35110 has devpath '/devices/virtual/net/lo'
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: device 0x7fef36c35110 filled with db file data
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: lo              : udev initialized link
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: lo              : saved original MTU: 0
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: lo              : Adding address: ::1/128 (valid for ever)
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: lo              : Adding address: 127.0.0.1/8 (valid for ever)
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: Enumeration completed
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f3        : link state is up-to-date
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: device 0x7fef36c27990 has devpath '/devices/pci0000:00/0000:00:01.1/0000:04:00.3'
Feb 11 14:21:47 jekeller-copperpass systemd[1]: Started Network Service.
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f3        : unmanaged
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: Sent message type=signal sender=n/a destination=n/a object=/org/freedesktop/network1/link/_37 interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=5 reply_cookie=0 error=n/a
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f2        : link state is up-to-date
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: device 0x7fef36c37810 has devpath '/devices/pci0000:00/0000:00:01.1/0000:04:00.2'
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f2        : unmanaged
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: Sent message type=signal sender=n/a destination=n/a object=/org/freedesktop/network1/link/_36 interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=6 reply_cookie=0 error=n/a
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f1        : link state is up-to-date
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: device 0x7fef36c37ac0 has devpath '/devices/pci0000:00/0000:00:01.1/0000:04:00.1'
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f1        : unmanaged
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: Sent message type=signal sender=n/a destination=n/a object=/org/freedesktop/network1/link/_35 interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=7 reply_cookie=0 error=n/a
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f0        : link state is up-to-date
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: device 0x7fef36c2ac30 has devpath '/devices/pci0000:00/0000:00:01.1/0000:04:00.0'
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f0        : found matching network '/etc/systemd/network/enp4s0f0.network'
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: Sent message type=signal sender=n/a destination=n/a object=/org/freedesktop/network1/link/_34 interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=8 reply_cookie=0 error=n/a
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f0        : bringing link up
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: Sent message type=signal sender=n/a destination=n/a object=/org/freedesktop/network1/link/_34 interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=9 reply_cookie=0 error=n/a
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: Sent message type=signal sender=n/a destination=n/a object=/org/freedesktop/network1/link/_34 interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=10 reply_cookie=0 error=n/a
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: ens9            : link state is up-to-date
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: device 0x7fef36c2b990 has devpath '/devices/pci0000:00/0000:00:02.0/0000:06:00.0/0000:07:09.0/0000:09:00.0'
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: ens9            : unmanaged
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: Sent message type=signal sender=n/a destination=n/a object=/org/freedesktop/network1/link/_33 interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=11 reply_cookie=0 error=n/a
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: ens8            : link state is up-to-date
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: device 0x7fef36c35b30 has devpath '/devices/pci0000:00/0000:00:02.0/0000:06:00.0/0000:07:08.0/0000:08:00.0'
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: ens8            : unmanaged
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: Sent message type=signal sender=n/a destination=n/a object=/org/freedesktop/network1/link/_32 interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=12 reply_cookie=0 error=n/a
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: lo              : link state is up-to-date
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: lo              : unmanaged
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: Sent message type=signal sender=n/a destination=n/a object=/org/freedesktop/network1/link/_31 interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=13 reply_cookie=0 error=n/a
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f0        : flags change: +UP
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: Sent message type=signal sender=n/a destination=n/a object=/org/freedesktop/network1/link/_34 interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=14 reply_cookie=0 error=n/a
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: Sent message type=signal sender=n/a destination=n/a object=/org/freedesktop/network1 interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=15 reply_cookie=0 error=n/a
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: enp4s0f0        : enp4s0f0        : could not bring up interface: Invalid argument
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: Got message type=signal sender=org.freedesktop.DBus destination=:1.1 object=/org/freedesktop/DBus interface=org.freedesktop.DBus member=NameAcquired cookie=2 reply_cookie=0 error=n/a
Feb 11 14:21:47 jekeller-copperpass systemd-networkd[1068]: Got message type=signal sender=org.freedesktop.DBus destination=:1.1 object=/org/freedesktop/DBus interface=org.freedesktop.DBus member=NameAcquired cookie=4 reply_cookie=0 error=n/a
Feb 11 14:21:51 jekeller-copperpass systemd-networkd[1068]: enp4s0f0        : flags change: +LOWER_UP +RUNNING
Feb 11 14:21:51 jekeller-copperpass systemd-networkd[1068]: Sent message type=signal sender=n/a destination=n/a object=/org/freedesktop/network1/link/_34 interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=16 reply_cookie=0 error=n/a
Feb 11 14:21:51 jekeller-copperpass systemd-networkd[1068]: Sent message type=signal sender=n/a destination=n/a object=/org/freedesktop/network1 interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=17 reply_cookie=0 error=n/a
Feb 11 14:21:51 jekeller-copperpass systemd-networkd[1068]: enp4s0f0        : gained carrier
Feb 11 14:21:51 jekeller-copperpass systemd-networkd[1068]: enp4s0f0        : acquiring DHCPv4 lease
Feb 11 14:21:51 jekeller-copperpass systemd-networkd[1068]: DHCP CLIENT (0xc7096673): STARTED on ifindex 4
Feb 11 14:21:51 jekeller-copperpass systemd-networkd[1068]: device 0x7fef36c2cb80 has devpath '/devices/pci0000:00/0000:00:01.1/0000:04:00.0/net/enp4s0f0'
Feb 11 14:21:51 jekeller-copperpass systemd-networkd[1068]: device 0x7fef36c2cb80 filled with db file data
Feb 11 14:21:51 jekeller-copperpass systemd-networkd[1068]: DHCP CLIENT (0xc7096673): DISCOVER
Feb 11 14:21:52 jekeller-copperpass systemd-networkd[1068]: DHCP CLIENT (0xc7096673): could not receive message from raw socket: Invalid argument