OK, I’ve set NetworkManager to logging TRACE level and analyzed journal im problem case. I’ve found following:
Both eth0 and eth1 startups are similar, but there is difference:
eth0 configuration ends with:
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.2692] device[0x56530891e8e0] (eth0): bringing up device 2
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.2692] platform: link: setting up "eth0" (2)
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.2692] platform-linux: link: change 2: flags: set 0x1/0x1 ([up] / [up])
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.4874] platform-linux: do-request-link: 2
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <trace> [1531510407.4874] platform-linux: event-notification: RTM_NEWLINK, flags 0, seq 0: 2: eth0 <UP;broadcast,multicast,up> mtu 1500 arp 1 ethernet? not-init addrgenmode none addr **[FILTERED]** rx:0,0 tx:0,0
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.4875] platform: signal: link changed: 2: eth0 <UP;broadcast,multicast,up> mtu 1500 arp 1 ethernet? init addrgenmode none addr **[FILTERED]** driver e1000e rx:0,0 tx:0,0
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <trace> [1531510407.4875] platform-linux: event-notification: RTM_NEWLINK, flags 0, seq 11: 2: eth0 <UP;broadcast,multicast,up> mtu 1500 arp 1 ethernet? not-init addrgenmode none addr **[FILTERED]** rx:0,0 tx:0,0
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.4876] platform-linux: do-change-link[2]: success changing link: success
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <trace> [1531510407.4876] ethtool[2]: ETHTOOL_GLINK, eth0: success
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.4876] device[0x56530891e8e0] (eth0): add_pending_action (1): 'carrier-wait'
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.4876] device[0x56530891e8e0] (eth0): preparing device
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.4876] device[0x56530891e8e0] (eth0): clearing queued IP4 config change
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.4877] device[0x56530891e8e0] (eth0): clearing queued IP6 config change
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <trace> [1531510407.4877] device[0x56530891e8e0] (eth0): remove_pending_action (1): 'dhcp6' not pending (expected)
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <trace> [1531510407.4877] device[0x56530891e8e0] (eth0): remove_pending_action (1): 'autoconf6' not pending (expected)
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.4877] platform-linux: sysctl: setting '/proc/sys/net/ipv6/conf/eth0/accept_ra' to '0' (current value is '1')
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.4878] platform-linux: sysctl: setting '/proc/sys/net/ipv6/conf/eth0/use_tempaddr' to '0' (current value is identical)
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.4878] device[0x56530891e8e0] (eth0): ip4-config: update (commit=1, new-config=(nil))
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.4878] device[0x56530891e8e0] (eth0): ip4-config: clear IP4Config instance (/org/freedesktop/NetworkManager/IP4Config/1)
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.4878] dns-mgr: (device_ip4_config_changed): queueing DNS updates (1)
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.4878] dns-mgr: (device_ip4_config_changed): DNS configuration did not change
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.4879] dns-mgr: (device_ip4_config_changed): no DNS changes to commit (0)
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <trace> [1531510407.4879] exported-object[0x56530892c1c0]: unexport: "/org/freedesktop/NetworkManager/IP4Config/1"
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.4880] device[0x56530891e8e0] (eth0): ip6-config: update (commit=1, new-config=(nil))
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.4880] device[0x56530891e8e0] (eth0): ip6-config: clear IP6Config instance (/org/freedesktop/NetworkManager/IP6Config/1)
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.4880] dns-mgr: (device_ip6_config_changed): queueing DNS updates (1)
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.4881] dns-mgr: (device_ip6_config_changed): DNS configuration did not change
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.4881] dns-mgr: (device_ip6_config_changed): no DNS changes to commit (0)
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <trace> [1531510407.4881] exported-object[0x565308935280]: unexport: "/org/freedesktop/NetworkManager/IP6Config/1"
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.4883] device[0x56530891e8e0] (eth0): device not yet available for transition to DISCONNECTED
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <trace> [1531510407.4885] ethtool[4]: ETHTOOL_GLINK, eth1: success
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.4885] device[0x56530892bea0] (eth1): constructed (NMDeviceEthernet)
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.4885] device[0x56530892bea0] (eth1): start setup of NMDeviceEthernet, kernel ifindex 4
Black lines are only for eth0 (probably it has something with detected link for eth0)
Green lines show eth1 configuration startup
eth1 configuration ends with:
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.4914] device[0x56530892bea0] (eth1): bringing up device 4
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.4914] platform: link: setting up "eth1" (4)
Jul 13 21:33:27 [filtered] NetworkManager[1726]: <debug> [1531510407.4915] platform-linux: link: change 4: flags: set 0x1/0x1 ([up] / [up])
That’s fine.
What is interesting, NetworkManager log in problem case ends with these three red lines for eth1 and in journal are no other entries from NetworkManager. But in “normal” case (USB2Ethernet disconnected), NetworkManager continues with wlan0 interface setup (same journal timestamp).
Jul 13 21:37:29 [filtered] NetworkManager[1626]: <debug> [1531510649.5590] wifi-nl80211: genl_ctrl_resolve: resolved "nl80211" as 0x1c
Jul 13 21:37:29 [filtered] NetworkManager[1626]: <info> [1531510649.5592] wifi-nl80211: (wlan0): using nl80211 for WiFi device control
Jul 13 21:37:29 [filtered] NetworkManager[1626]: <debug> [1531510649.5598] device[0x5583a07d1c50] (wlan0): constructed (NMDeviceWifi)
This step is not not done in problem case. Do you have some explanation?