networkd starts before udev

[crawford]

Issue Report

Bug

CoreOS Version

NAME="Container Linux by CoreOS"
ID=coreos
VERSION=1284.2.0
VERSION_ID=1284.2.0
BUILD_ID=2017-01-10-0545
PRETTY_NAME="Container Linux by CoreOS 1284.2.0 (Ladybug)"
ANSI_COLOR="38;5;75"
HOME_URL="https://coreos.com/"
BUG_REPORT_URL="https://github.com/coreos/bugs/issues"

Environment

All

Expected Behavior

udev is able to rename interfaces.

Actual Behavior

Errors like the following are seen because networkd starts before udev:

Jan 16 23:55:16 localhost systemd-udevd[1315]: Error changing net interface name 'eth2' to 'ens802f0': Device or resource busy
Jan 16 23:55:16 localhost systemd-udevd[1315]: could not rename interface '4' from 'eth2' to 'ens802f0': Device or resource busy

[qrpike]

I am getting this error on only 1 machine. Latest CoreOS stable. It's an intel NIC if that matters.

[dm0-]

Is there a reliable way to reproduce this error? I haven't seen it, and the upstream systemd-networkd.service has After=systemd-udevd.service on all channels.

[ndenev]

We're also seeing this. While systemd-udevd.service does start shortly before systemd-networkd.service, there are Error changing net interface name entries, and from boot to boot I get a different combinations of eth* and eno* interfaces (some renamed some not)

[stg] root@k8s1-5 system # journalctl -o short-precise -u systemd-networkd.service | head -n2
-- Logs begin at Fri 2017-05-05 10:36:45 UTC, end at Fri 2017-05-05 11:32:44 UTC. --
May 05 10:36:45.647795 localhost systemd[1]: Starting Network Service...
[stg] root@k8s1-5 system # journalctl -o short-precise -u systemd-udevd.service | head -n2
-- Logs begin at Fri 2017-05-05 10:36:45 UTC, end at Fri 2017-05-05 11:32:50 UTC. --
May 05 10:36:45.642651 localhost systemd[1]: Starting udev Kernel Device Manager...
[stg] root@k8s1-5 system #

May 05 10:36:45.775588 localhost kernel: tg3 0000:02:00.0 eth0: Tigon3 [partno(BCM95720) rev 5720000] (PCI Express) MAC address 14:18:77:66:63:b2
May 05 10:36:45.775763 localhost kernel: tg3 0000:02:00.0 eth0: attached PHY is 5720C (10/100/1000Base-T Ethernet) (WireSpeed[1], EEE[1])
May 05 10:36:45.775922 localhost kernel: tg3 0000:02:00.0 eth0: RXcsums[1] LinkChgREG[0] MIirq[0] ASF[1] TSOcap[1]
May 05 10:36:45.776117 localhost kernel: tg3 0000:02:00.0 eth0: dma_rwctrl[00000001] dma_mask[64-bit]
May 05 10:36:45.791031 localhost kernel: tg3 0000:02:00.1 eth1: Tigon3 [partno(BCM95720) rev 5720000] (PCI Express) MAC address 14:18:77:66:63:b3
May 05 10:36:45.791126 localhost kernel: tg3 0000:02:00.1 eth1: attached PHY is 5720C (10/100/1000Base-T Ethernet) (WireSpeed[1], EEE[1])
May 05 10:36:45.791217 localhost kernel: tg3 0000:02:00.1 eth1: RXcsums[1] LinkChgREG[0] MIirq[0] ASF[1] TSOcap[1]
May 05 10:36:45.791295 localhost kernel: tg3 0000:02:00.1 eth1: dma_rwctrl[00000001] dma_mask[64-bit]
May 05 10:36:45.807288 localhost kernel: tg3 0000:03:00.0 eth2: Tigon3 [partno(BCM95720) rev 5720000] (PCI Express) MAC address 14:18:77:66:63:b4
May 05 10:36:45.807408 localhost kernel: tg3 0000:03:00.0 eth2: attached PHY is 5720C (10/100/1000Base-T Ethernet) (WireSpeed[1], EEE[1])
May 05 10:36:45.807497 localhost kernel: tg3 0000:03:00.0 eth2: RXcsums[1] LinkChgREG[0] MIirq[0] ASF[1] TSOcap[1]
May 05 10:36:45.807782 localhost kernel: tg3 0000:03:00.0 eth2: dma_rwctrl[00000001] dma_mask[64-bit]
May 05 10:36:45.829230 localhost kernel: tg3 0000:03:00.1 eth3: Tigon3 [partno(BCM95720) rev 5720000] (PCI Express) MAC address 14:18:77:66:63:b5
May 05 10:36:45.829326 localhost kernel: tg3 0000:03:00.1 eth3: attached PHY is 5720C (10/100/1000Base-T Ethernet) (WireSpeed[1], EEE[1])
May 05 10:36:45.829426 localhost kernel: tg3 0000:03:00.1 eth3: RXcsums[1] LinkChgREG[0] MIirq[0] ASF[1] TSOcap[1]
May 05 10:36:45.829535 localhost kernel: tg3 0000:03:00.1 eth3: dma_rwctrl[00000001] dma_mask[64-bit]
May 05 10:36:45.832921 localhost systemd-networkd[404]: eth3: IPv6 enabled for interface: Success
May 05 10:36:45.958443 localhost kernel: IPv6: ADDRCONF(NETDEV_UP): eth3: link is not ready
May 05 10:36:45.972112 localhost systemd-networkd[404]: eth0: IPv6 enabled for interface: Success
May 05 10:36:46.101679 localhost kernel: IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
May 05 10:36:46.342269 localhost systemd-networkd[404]: eth2: IPv6 enabled for interface: Success
May 05 10:36:46.468596 localhost kernel: IPv6: ADDRCONF(NETDEV_UP): eth2: link is not ready
May 05 10:36:46.468763 localhost systemd-networkd[404]: eth1: IPv6 enabled for interface: Success
May 05 10:36:46.593586 localhost kernel: IPv6: ADDRCONF(NETDEV_UP): eth1: link is not ready
May 05 10:36:50.273248 localhost systemd-udevd[1953]: Error changing net interface name 'eth2' to 'eno3': Device or resource busy
May 05 10:36:50.385293 localhost kernel: tg3 0000:03:00.1 eno4: renamed from eth3
May 05 10:36:50.385493 localhost kernel: tg3 0000:02:00.0 eno1: renamed from eth0
May 05 10:36:50.273259 localhost systemd-udevd[1953]: could not rename interface '4' from 'eth2' to 'eno3': Device or resource busy
May 05 10:36:50.288118 localhost systemd-udevd[1974]: Error changing net interface name 'eth1' to 'eno2': Device or resource busy
May 05 10:36:50.288124 localhost systemd-udevd[1974]: could not rename interface '3' from 'eth1' to 'eno2': Device or resource busy
May 05 10:36:51.877535 localhost systemd-networkd[3063]: eno4: IPv6 enabled for interface: Success
May 05 10:36:52.003593 localhost kernel: IPv6: ADDRCONF(NETDEV_UP): eno4: link is not ready
May 05 10:36:52.024205 localhost systemd-networkd[3063]: eno1: IPv6 enabled for interface: Success
May 05 10:36:52.734042 localhost kernel: IPv6: ADDRCONF(NETDEV_UP): eno1: link is not ready
May 05 10:36:55.827881 localhost kernel: tg3 0000:02:00.0 eno1: Link is up at 1000 Mbps, full duplex
May 05 10:36:55.827989 localhost kernel: tg3 0000:02:00.0 eno1: Flow control is off for TX and off for RX
May 05 10:36:55.828127 localhost kernel: tg3 0000:02:00.0 eno1: EEE is disabled
May 05 10:36:55.828760 localhost systemd-networkd[3063]: eno1: Gained carrier
May 05 10:36:55.828987 localhost kernel: IPv6: ADDRCONF(NETDEV_CHANGE): eno1: link becomes ready
May 05 10:36:57.473690 localhost systemd-networkd[3063]: eno1: Gained IPv6LL

This is on Stable-1298.7.0

[ndenev]

Of course setting debug in the kernel config line makes this work :(

[alialshamali]

I am getting the same error, when I reboot the server, its doesn't come up. After looking at the log I find

Error changing net interface name 'eth0' to 'eno1' : Device or resource busy

Only after rebooting the server it come up and take the configured IP address.

Is there any fix?

Just to add its a intel NIC too

[ndenev]

I resorted to disabling the "predictable" interface names altogether and use ethX naming.

[alialshamali]

Thanks @ndenev
Seems to be a workaround, but wondering what is the root cause. I am trying to analyze to figure what in the kernel is causing this behavior. Its very strange.

[alialshamali]

I notice the issue was resolved when I removed the multiple ip addresses from the interface and restart ed the interface. Can this be related? Once I did that I no longer have this issue.

[paulmcgoldrick]

Same issue.

[Thu Aug  3 16:45:49 2017] IPv6: ADDRCONF(NETDEV_CHANGE): eth7: link becomes ready
[Thu Aug  3 16:45:51 2017] igb 0000:01:00.1 eno2: renamed from eth1
[Thu Aug  3 16:45:51 2017] igb 0000:01:00.2 eno3: renamed from eth2
[Thu Aug  3 16:45:51 2017] igb 0000:01:00.0 eno1: renamed from eth0
[Thu Aug  3 16:45:51 2017] igb 0000:01:00.3 eno4: renamed from eth3
[Thu Aug  3 16:45:51 2017] ixgbe 0000:44:00.0 enp68s0f0: renamed from eth6
[Thu Aug  3 16:45:51 2017] ixgbe 0000:43:00.0 enp67s0f0: renamed from eth4
[Thu Aug  3 16:45:51 2017] ixgbe 0000:43:00.1 enp67s0f1: renamed from eth5

Aug 03 16:45:47 localhost systemd-udevd[1425]: Error changing net interface name 'eth7' to 'enp68s0f1': Device or resource busy
Aug 03 16:45:47 localhost systemd-udevd[1425]: could not rename interface '9' from 'eth7' to 'enp68s0f1': Device or resource busy

coreos-16 etc # cat /etc/os-release
NAME="Container Linux by CoreOS"
ID=coreos
VERSION=1409.6.0
VERSION_ID=1409.6.0
BUILD_ID=2017-07-06-0128
PRETTY_NAME="Container Linux by CoreOS 1409.6.0 (Ladybug)"
ANSI_COLOR="38;5;75"
HOME_URL="https://coreos.com/"
BUG_REPORT_URL="https://issues.coreos.com"
COREOS_BOARD="amd64-usr"