[systemd-devel] systemd-networkd: no network connectivity with 214/master due to 63a070415db09f5b5bcc5c

[Tom Gundersen]

On Fri, Jun 20, 2014 at 12:12 PM, Michal Sekletar <msekleta at redhat.com> wrote:
> On Wed, Jun 18, 2014 at 09:51:02PM +0200, Friedrich Kröner wrote:
>> Hello,
>>
>> when trying systemd-networkd with >=214 and the following config:
>>
>> [Match]
>> Name=eth*
>>
>> [Network]
>> DHCP=yes
>>
>> Address=2001:db8::1234:5678/64
>> DNS=8.8.8.8
>> DNS=2001:db8:1::ab9:C0A8:102
>>
>>
>> I get lots of DHCP DISCOVER events and it doesn't aquire an IPv4 address, nor
>> sets the configured IPv6.
>>
>> Jun 18 18:44:31 localhost systemd[1]: Starting Network Service...
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: timestamp of
>> '/etc/systemd/network' changed
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: sd-rtnl: discarding 20
>> bytes of incoming message
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: eth0            : link 3
>> added
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: eth0            : udev
>> initialized link
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: eth0            : flags
>> change: +UP +LOWER_UP +RUNNING +MULTICAST +BROADCAST
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: eth0            : gained
>> carrier
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: could not add new link
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: lo              : link 1
>> added
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: lo              : udev
>> initialized link
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: lo              : flags
>> change: +LOOPBACK +UP +LOWER_UP +RUNNING
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: lo              : gained
>> carrier
>> Jun 18 18:44:31 localhost systemd[1]: Started Network Service.
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: eth0            : link
>> state is up-to-date
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: eth0            : found
>> matching network '/etc/systemd/network/80-dhcp.network'
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: eth0            : acquiring
>> DHCPv4 lease
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: DHCP CLIENT (0x3ddf8f7):
>> STARTED on ifindex 3 with address 52:54:e4:d2:24:44
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: 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
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: DHCP CLIENT (0x3ddf8f7):
>> DISCOVER
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: lo              : getting
>> address failed: Device or resource busy
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: lo              : link
>> state is up-to-date
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: lo              : unmanaged
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: sd-rtnl: discarding 20
>> bytes of incoming message
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: eth0            : added
>> address: fe80::5054:e4ff:fed2:2444/64
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: rtnl: received address for
>> a nonexistent link, ignoring
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: lo              : added
>> address: ::1/128
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: eth0            : added
>> address: 123.23.23.21/22
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: lo              : added
>> address: 127.0.0.1/8
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: Got message
>> type=method_return sender=org.freedesktop.DBus destination=:1.45 object=n/a
>> interface=n/a member=n/a cookie=1 reply_cookie=1 error=n/a
>> Jun 18 18:44:31 localhost systemd-networkd[19468]: Got message type=signal
>> sender=org.freedesktop.DBus destination=:1.45 object=/org/freedesktop/DBus
>> interface=org.freedesktop.DBus member=NameAcquired cookie=2 reply_cookie=0
>> error=n/a
>> Jun 18 18:44:33 localhost systemd-networkd[19468]: DHCP CLIENT (0x3ddf8f7):
>> DISCOVER
>> Jun 18 18:44:34 localhost systemd-networkd[19468]: DHCP CLIENT (0x3ddf8f7):
>> DISCOVER
>> Jun 18 18:44:38 localhost systemd-networkd[19468]: DHCP CLIENT (0x3ddf8f7):
>> DISCOVER
>> Jun 18 18:44:46 localhost systemd-networkd[19468]: DHCP CLIENT (0x3ddf8f7):
>> DISCOVER
>> Jun 18 18:45:02 localhost systemd-networkd[19468]: DHCP CLIENT (0x3ddf8f7):
>> DISCOVER
>> Jun 18 18:45:33 localhost systemd-networkd[19468]: DHCP CLIENT (0x3ddf8f7):
>> DISCOVER
>> Jun 18 18:46:36 localhost systemd-networkd[19468]: DHCP CLIENT (0x3ddf8f7):
>> DISCOVER
>> Jun 18 18:47:41 localhost systemd-networkd[19468]: DHCP CLIENT (0x3ddf8f7):
>> DISCOVER
>> Jun 18 18:48:44 localhost systemd-networkd[19468]: DHCP CLIENT (0x3ddf8f7):
>> DISCOVER
>>
>> reverting commit 63a070415db09f5b5bcc5c sd-dhcp-client: allways request
>> broadcast
>> restores the previous behavior. Upon restart of systemd-networkd I get the
>> usual OFFER, REQUEST, ACK confirmation and the IPv6 gets set as well.
>>
>> This is on a kvm-machine with virtio_net as module.
>>
>> Please let me know if you want me to test anything or need further
>> information.
>
> What DHCP server do you use? I was running networkd with 63a070415db09f5b5bcc5c
> included and was able to obtain offers just fine on qemu-kvm vms using dnsmasq
> as DHCP server.

Thanks guys for looking into this. I finally got my containers working
again today so I could reproduce. There was a bug in sd-dhcp-server so
that it would never send out broadcast packets (so the change
defaulting to requesting broadcast in the client obviously broke
everything). I fixed that now in git, so let me know if there are any
more problems.

Cheers,

Tom