[systemd-devel] assert() when restarting systemd-networkd

Michael Olbrich m.olbrich at pengutronix.de
Sun Jul 20 06:12:41 PDT 2014


Hi,

with the current git master (v215-293-g4e6029435111) restarting
systemd-networkd triggers an assert() here:

In netdev_join_handler():
        assert(IN_SET(link->state, LINK_STATE_ENSLAVING, LINK_STATE_FAILED,
                      LINK_STATE_LINGER));

gdb tells me that link->state is LINK_STATE_SETTING_ADDRESSES here.

It doesn't happen all the time, but when it happens, then the assert()
tiggers until the start limit kicks in.

My configuration looks like this:
-------- eth0.network-----------
[Match]
Name=eth0

[Network]
DHCP=v4
IPv4LL=yes
MACVLAN=vlan0
-------- vlan0.netdev------------
[NetDev]
Name=vlan0
Kind=macvlan
[MACVLAN]
Mode=private
-------- vlan0.network-----------
[Match]
Name=vlan0

[Network]
Address=10.1.42.4/24
---------------------------------

After adding Environment=SYSTEMD_LOG_LEVEL=debug to the service the journal
looks like this:

Jul 01 00:13:39 BaseKit systemd[1]: Starting Network Service...
Jul 01 00:13:39 BaseKit systemd-networkd[553]: timestamp of '/lib/systemd/network' changed
Jul 01 00:13:39 BaseKit systemd-networkd[553]: vlan0           : loaded macvlan
Jul 01 00:13:39 BaseKit systemd-networkd[553]: sd-rtnl: discarding 20 bytes of incoming message
Jul 01 00:13:39 BaseKit systemd-networkd[553]: vlan0           : link 3 added
Jul 01 00:13:39 BaseKit systemd-networkd[553]: vlan0           : udev initialized link
Jul 01 00:13:39 BaseKit systemd-networkd[553]: vlan0           : netdev has index 3
Jul 01 00:13:39 BaseKit systemd-networkd[553]: vlan0           : flags change: +UP +LOWER_UP +RUNNING +MULTICAST +BROADCAST
Jul 01 00:13:39 BaseKit systemd-networkd[553]: vlan0           : gained carrier
Jul 01 00:13:39 BaseKit systemd-networkd[553]: eth0            : link 2 added
Jul 01 00:13:39 BaseKit systemd-networkd[553]: eth0            : udev initialized link
Jul 01 00:13:39 BaseKit systemd-networkd[553]: eth0            : flags change: +UP +LOWER_UP +RUNNING +MULTICAST +BROADCAST
Jul 01 00:13:39 BaseKit systemd-networkd[553]: eth0            : gained carrier
Jul 01 00:13:39 BaseKit systemd-networkd[553]: lo              : link 1 added
Jul 01 00:13:39 BaseKit systemd-networkd[553]: lo              : udev initialized link
Jul 01 00:13:39 BaseKit systemd-networkd[553]: lo              : flags change: +LOOPBACK +UP +LOWER_UP +RUNNING
Jul 01 00:13:39 BaseKit systemd-networkd[553]: lo              : gained carrier
Jul 01 00:13:39 BaseKit systemd[1]: Started Network Service.
Jul 01 00:13:39 BaseKit systemd-networkd[553]: vlan0           : link state is up-to-date
Jul 01 00:13:39 BaseKit systemd-networkd[553]: vlan0           : found matching network '/lib/systemd/network/vlan0.network'
Jul 01 00:13:39 BaseKit systemd-networkd[553]: vlan0           : joined netdev
Jul 01 00:13:39 BaseKit systemd-networkd[553]: vlan0           : setting addresses
Jul 01 00:13:39 BaseKit systemd-networkd[553]: 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
Jul 01 00:13:39 BaseKit systemd-networkd[553]: Got message type=method_return sender=org.freedesktop.DBus destination=:1.26 object=n/a interface=n/a member=n/a cookie=1 reply_cookie=1 error=n/a
Jul 01 00:13:39 BaseKit systemd-networkd[553]: eth0            : getting address failed: Device or resource busy
Jul 01 00:13:39 BaseKit systemd-networkd[553]: Got message type=signal sender=org.freedesktop.DBus destination=:1.26 object=/org/freedesktop/DBus interface=org.freedesktop.DBus member=NameAcquired cookie=2 reply_cookie=0 error=n/a
Jul 01 00:13:39 BaseKit systemd-networkd[553]: eth0            : link state is up-to-date
Jul 01 00:13:39 BaseKit systemd-networkd[553]: eth0            : found matching network '/lib/systemd/network/eth0.network'
Jul 01 00:13:39 BaseKit systemd-networkd[553]: eth0            : acquiring IPv4 link-local address
Jul 01 00:13:39 BaseKit systemd-networkd[553]: eth0            : acquiring DHCPv4 lease
Jul 01 00:13:39 BaseKit systemd-networkd[553]: DHCP CLIENT (0x97290dbb): STARTED on ifindex 2 with address 52:54:0:12:34:56
Jul 01 00:13:39 BaseKit systemd-networkd[553]: eth0            : enslaving by 'vlan0'
Jul 01 00:13:39 BaseKit systemd-networkd[553]: IPv4LL: PROBE
Jul 01 00:13:39 BaseKit systemd-networkd[553]: DHCP CLIENT (0x97290dbb): DISCOVER
Jul 01 00:13:39 BaseKit systemd-networkd[553]: lo              : getting address failed: Device or resource busy
Jul 01 00:13:39 BaseKit systemd-networkd[553]: DHCP CLIENT (0x97290dbb): OFFER
Jul 01 00:13:39 BaseKit systemd-networkd[553]: lo              : link state is up-to-date
Jul 01 00:13:39 BaseKit systemd-networkd[553]: lo              : unmanaged
Jul 01 00:13:39 BaseKit systemd-networkd[553]: DHCP CLIENT (0x97290dbb): REQUEST (requesting)
Jul 01 00:13:39 BaseKit systemd-networkd[553]: DHCP CLIENT (0x97290dbb): ACK
Jul 01 00:13:39 BaseKit systemd-networkd[553]: DHCP CLIENT (0x97290dbb): lease expires in 4min 31.009207s
Jul 01 00:13:39 BaseKit systemd-networkd[553]: DHCP CLIENT (0x97290dbb): T2 expires in 3min 56.182129s
Jul 01 00:13:39 BaseKit systemd-networkd[553]: DHCP CLIENT (0x97290dbb): T1 expires in 2min 14.923630s
Jul 01 00:13:39 BaseKit systemd-networkd[553]: eth0            : DHCPv4 address 192.168.51.130/24 via 192.168.51.1
Jul 01 00:13:39 BaseKit systemd-networkd[553]: eth0            : setting addresses
Jul 01 00:13:39 BaseKit systemd-networkd[553]: IPv4LL: STOPPED
Jul 01 00:13:39 BaseKit systemd-networkd[553]: sd-rtnl: discarding 20 bytes of incoming message
Jul 01 00:13:39 BaseKit systemd-networkd[553]: vlan0           : added address: fe80::ecb2:e4ff:fee9:9371/64
Jul 01 00:13:39 BaseKit systemd-networkd[553]: eth0            : added address: fe80::5054:ff:fe12:3456/64
Jul 01 00:13:40 BaseKit systemd-networkd[553]: lo              : added address: ::1/128
Jul 01 00:13:40 BaseKit systemd-networkd[553]: vlan0           : added address: 10.1.42.4/24
Jul 01 00:13:40 BaseKit systemd-networkd[553]: eth0            : added address: 192.168.51.130/24
Jul 01 00:13:40 BaseKit systemd-networkd[553]: lo              : added address: 127.0.0.1/8
Jul 01 00:13:40 BaseKit systemd-networkd[553]: vlan0           : addresses set
Jul 01 00:13:40 BaseKit systemd-networkd[553]: vlan0           : link configured
Jul 01 00:13:40 BaseKit systemd-networkd[553]: Assertion '({ const typeof(LINK_STATE_ENSLAVING) _y = (LINK_STATE_ENSLAVING); const typeof(_y) _x = (link->state); unsigned _i; _Bool _found = 0; for (_i = 0; _i < 1 + sizeof((const typeof(_x)[]) { LINK_STATE_FAILED, LINK_STATE_LINGER })/sizeof(const typeof(_x)); _i++) if (((const typeof(_x)[]) { _y, LINK_STATE_FAILED, LINK_STATE_LINGER })[_i] == _x) { _found = 1; break; } _found; })' failed at src/network/networkd-link.c:1759, function netdev_join_handler(). Aborting.
Jul 01 00:13:40 BaseKit systemd[1]: Unit systemd-networkd.service entered failed state.

I have no idea what happens here. Maybe someone with more knowledge about
the internals of systemd-networkd has an idea.

Michael

-- 
Pengutronix e.K.                           |                             |
Industrial Linux Solutions                 | http://www.pengutronix.de/  |
Peiner Str. 6-8, 31137 Hildesheim, Germany | Phone: +49-5121-206917-0    |
Amtsgericht Hildesheim, HRA 2686           | Fax:   +49-5121-206917-5555 |


More information about the systemd-devel mailing list