[systemd-devel] [networkd] Event source …: Operation not supported

[Mark Oteiza]

Hi,

networkd on systemd v215 starts churning after printing the error in the
subject.  The issue is present on git master.

Config:

# /etc/systemd/network/dhcp.network

[Match]
Name=bond0

[Network]
Description=DHCPv4 client
DHCP=true

# /etc/systemd/network/ethernet.link

[Match]
Driver=r8169
Path=pci-0000:05:00.0

[Link]
Description=Ethernet link
WakeOnLan=off

# /etc/systemd/network/ethernet.network

[Match]
Name=enp5s0

[Network]
Bond=bond0

# /etc/systemd/network/virtual.netdev

[NetDev]
Name=bond0
Kind=bond

# /etc/systemd/network/wireless.network

[Match]
Name=wlp2s0

[Network]
Bond=bond0

Log:

 # SYSTEMD_LOG_LEVEL=debug strace -tt -o/tmp/sd.log /usr/lib/systemd/systemd-networkd
 timestamp of '/etc/systemd/network' changed
 timestamp of '/usr/lib/systemd/network' changed
 bond0           : creating netdev
 bond0           : loaded bond
 sd-rtnl: discarding 20 bytes of incoming message
 bond0           : link 4 added
 bond0           : udev initialized link
 bond0           : netdev has index 4
 bond0           : netdev ready
 bond0           : flags change: +MASTER +UP +LOWER_UP +RUNNING +MULTICAST +BROADCAST +DYNAMIC
 bond0           : gained carrier
 wlp2s0          : link 3 added
 wlp2s0          : udev initialized link
 wlp2s0          : flags change: +SLAVE +UP +LOWER_UP +RUNNING +MULTICAST +BROADCAST
 wlp2s0          : gained carrier
 enp5s0          : link 2 added
 enp5s0          : udev initialized link
 enp5s0          : flags change: +SLAVE +UP +MULTICAST +BROADCAST
 lo              : link 1 added
 lo              : udev initialized link
 lo              : flags change: +LOOPBACK +UP +LOWER_UP +RUNNING
 lo              : gained carrier
 bond0           : netdev exists, using existing
 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
 bond0           : link state is up-to-date
 bond0           : found matching network '/etc/systemd/network/dhcp.network'
 bond0           : acquiring DHCPv4 lease
 DHCP CLIENT (0xb93b6f3f): STARTED on ifindex 4 with address 88:53:2e:d8:f7:43
 bond0           : discovering IPv6 routers
 bond0           : could not start IPv6 router discovery
 Event source 0x7fcc5e9f4ae0 returned error, disabling: Address family not supported by protocol
 Got message type=method_return sender=org.freedesktop.DBus destination=:1.258 object=n/a interface=n/a member=n/a cookie=1 reply_cookie=1 error=n/a
 DHCP CLIENT (0xb93b6f3f): DISCOVER
 Got message type=signal sender=org.freedesktop.DBus destination=:1.258 object=/org/freedesktop/DBus interface=org.freedesktop.DBus member=NameAcquired cookie=2 reply_cookie=0 error=n/a
 DHCP CLIENT (0xb93b6f3f): DISCOVER
 DHCP CLIENT (0xb93b6f3f): DISCOVER
 DHCP CLIENT (0xb93b6f3f): OFFER
 DHCP CLIENT (0xb93b6f3f): REQUEST (requesting)
 DHCP CLIENT (0xb93b6f3f): ACK
 DHCP CLIENT (0xb93b6f3f): lease expires in 23h 59min 58.249276s
 DHCP CLIENT (0xb93b6f3f): T2 expires in 20h 59min 57.377539s
 DHCP CLIENT (0xb93b6f3f): T1 expires in 11h 59min 59.669139s
 bond0           : DHCPv4 address 192.168.1.3/24 via 192.168.1.1
 bond0           : setting addresses
 Event source 0x7fcc5e9f4d40 returned error, disabling: Operation not supported
 ^CReceived SIGINT.
 DHCP CLIENT (0xb93b6f3f): FREE

Perhaps a relevant part of the strace:

16:21:20.322639 writev(2, [{"bond0           : setting addres"..., 35}, {"\n", 1}], 2) = 36
16:21:20.322722 sendto(4, "<\0\0\0\24\0\5\1\n\0\0\0\0\0\0\0\2\30\200\0\4\0\0\0\10\0\2\0\300\250\1\3"..., 60, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 16) = 60
16:21:20.322851 epoll_ctl(3, EPOLL_CTL_DEL, 9, NULL) = 0
16:21:20.322926 clone(child_stack=0x7fcc5d5f0f30, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tidptr=0x7fcc5d5f19d0, tls=0x7fcc5d5f1700, child_tidptr=0x7fcc5d5f19d0) = 2148
16:21:20.323016 timerfd_settime(8, TFD_TIMER_ABSTIME, {it_interval={0, 0}, it_value={889, 596126000}}, NULL) = 0
16:21:20.323081 epoll_wait(3, {{EPOLLIN, {u32=2, u64=2}}}, 12, -1) = 1
16:21:41.076821 clock_gettime(0x7 /* CLOCK_??? */, {889, 596521449}) = 0
16:21:41.077077 read(8, "\1\0\0\0\0\0\0\0", 8) = 8
16:21:41.077312 writev(2, [{"Event source 0x7fcc5e9f4d40 retu"..., 78}, {"\n", 1}], 2) = 79
16:21:41.077482 timerfd_settime(8, TFD_TIMER_ABSTIME, {it_interval={0, 0}, it_value={44068, 520006000}}, NULL) = 0
16:21:41.077641 epoll_wait(3, {}, 12, 0) = 0
16:21:41.077761 clock_gettime(0x7 /* CLOCK_??? */, {889, 597406932}) = 0
16:21:41.077899 recvmsg(5, 0x7fffca25a710, MSG_DONTWAIT|MSG_NOSIGNAL|MSG_CMSG_CLOEXEC) = -1 EAGAIN (Resource temporarily unavailable)
16:21:41.078040 timerfd_settime(8, TFD_TIMER_ABSTIME, {it_interval={0, 0}, it_value={889, 596126000}}, NULL) = 0
16:21:41.078153 epoll_wait(3, {{EPOLLIN, {u32=2, u64=2}}}, 12, -1) = 1
16:21:41.078276 clock_gettime(0x7 /* CLOCK_??? */, {889, 597929368}) = 0
16:21:41.078417 read(8, "\1\0\0\0\0\0\0\0", 8) = 8
16:21:41.078560 recvmsg(5, 0x7fffca25a710, MSG_DONTWAIT|MSG_NOSIGNAL|MSG_CMSG_CLOEXEC) = -1 EAGAIN (Resource temporarily unavailable)
16:21:41.078689 timerfd_settime(8, TFD_TIMER_ABSTIME, {it_interval={0, 0}, it_value={889, 596126000}}, NULL) = 0
16:21:41.078798 epoll_wait(3, {{EPOLLIN, {u32=2, u64=2}}}, 12, -1) = 1
16:21:41.078917 clock_gettime(0x7 /* CLOCK_??? */, {889, 598569948}) = 0
16:21:41.079045 read(8, "\1\0\0\0\0\0\0\0", 8) = 8
16:21:41.079186 recvmsg(5, 0x7fffca25a710, MSG_DONTWAIT|MSG_NOSIGNAL|MSG_CMSG_CLOEXEC) = -1 EAGAIN (Resource temporarily unavailable)
16:21:41.079304 timerfd_settime(8, TFD_TIMER_ABSTIME, {it_interval={0, 0}, it_value={889, 596126000}}, NULL) = 0
16:21:41.079422 epoll_wait(3, {{EPOLLIN, {u32=2, u64=2}}}, 12, -1) = 1
16:21:41.079541 clock_gettime(0x7 /* CLOCK_??? */, {889, 599194041}) = 0
16:21:41.079667 read(8, "\1\0\0\0\0\0\0\0", 8) = 8