Bug 1960116
| Summary: | network-online.target reached before team interface gets carrier | ||||||||
|---|---|---|---|---|---|---|---|---|---|
| Product: | Red Hat Enterprise Linux 8 | Reporter: | suresh kumar <surkumar> | ||||||
| Component: | NetworkManager | Assignee: | NetworkManager Development Team <nm-team> | ||||||
| Status: | CLOSED DUPLICATE | QA Contact: | Desktop QE <desktop-qa-list> | ||||||
| Severity: | high | Docs Contact: | |||||||
| Priority: | high | ||||||||
| Version: | 8.3 | CC: | bgalvani, brainslug, ferferna, fge, lrintel, rkhan, sukulkar, thaller, till, upatel | ||||||
| Target Milestone: | beta | Keywords: | Triaged | ||||||
| Target Release: | --- | Flags: | pm-rhel:
mirror+
|
||||||
| Hardware: | All | ||||||||
| OS: | Linux | ||||||||
| Whiteboard: | |||||||||
| Fixed In Version: | Doc Type: | No Doc Update | |||||||
| Doc Text: | Story Points: | --- | |||||||
| Clone Of: | Environment: | ||||||||
| Last Closed: | 2022-04-05 09:16:56 UTC | Type: | Bug | ||||||
| Regression: | --- | Mount Type: | --- | ||||||
| Documentation: | --- | CRM: | |||||||
| Verified Versions: | Category: | --- | |||||||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |||||||
| Cloudforms Team: | --- | Target Upstream Version: | |||||||
| Embargoed: | |||||||||
| Attachments: |
|
||||||||
Created attachment 1782607 [details]
journalctl -u NetworkManager
it's because carrier for ens8 and ens9 comes only very later: ``` <info> [1620880644.5696] manager: startup complete ... <debug> [1620880646.1878] platform: (ens8) signal: link changed: 3: ens8 <UP,LOWER_UP;broadcast,m... ... <debug> [1620880646.3155] platform: (ens9) signal: link changed: 4: ens9 <UP,LOWER_UP;broadcast,m... ``` Interestingly, teamd takes another 3 seconds to notice that: ``` teamd_team0[1141]: ens8: ethtool-link went up. ``` I guess, you could configure ipv4.ping-gatway, but that is only a workaround. Beniamino, what do you think? > I guess, you could configure ipv4.ping-gatway, but that is only a workaround.
That should work as a workaround. I think a proper solution would be to delay startup complete until team0 gets carrier.
> I guess, you could configure ipv4.ping-gatway, but that is only a workaround.
As there is no default route configured on that interface, this wouldn't work.
Currently, in NetworkManager static IPv4 profiles can be activated without carrier (the purpose is that you could already bind your services to the IP address, without a cable plugged in). But there is no mechanism to say what carrier is actually required. As such, this interface is considered ready, once it's set up, has at least one port, and has the IP addresses configured. What it would require is an option where carrier becomes something that is required and that NetworkManager waits for a certain time -- before giving up (at which point the connection configurably fails or is considered ready (despite no carrier)).
An alternatve interesting feature would be that the gateway for ipv4.gateway-ping-timeout option is made configurable.
The workaround for "NetworkManager-wait-online.service" completing too early is creating your own service that does the desired waiting:
[Unit]
Description=Wait for Network Interface Ready
Wants=NetworkManager-wait-online.service
After=NetworkManager-wait-online.service
Before=network-online.target
[Service]
Type=oneshot
RemainAfterExit=yes
ExecStart=...
[Install]
WantedBy=network-online.target
which does whatever waiting is requested. E.g.
ExecStart=/bin/bash -c 'for i in {1..10} ; do ping -W 1 -c 1 192.168.122.1 &>/dev/null && exit 0; done; exit 1'
or
ExecStart=/bin/bash -c 'for i in {1..100} ; do ip link show team0 | grep -q -w LOWER_UP && exit 0; sleep 1; done; exit 1'
Hi! Could you let us know if the workaround provided by Thomas did work for you? Thank you! Thank you for the update, in that case I am lowering the priority. Thank you! Removing from the RPL based on lack of voting from all parties (CEE, Dev, QE). Please add it back if there is agreement to get it on the RPL. Thanks! Sushil We are planning to support an arbitrary delay to delay the nm-online target, therefore I close this as a duplicate of bug 2008337. This can then be used to delay the activation as necessary. *** This bug has been marked as a duplicate of bug 2008337 *** |
Created attachment 1782606 [details] journalctl -l Description of problem: network-online.target reached before team slaves are enslaved This results in connectivity issues for services depending on network-online.target Version-Release number of selected component (if applicable): NetworkManager-1.26.0-8.el8.x86_64 How reproducible: Always Steps to Reproduce: 1. Create a team interface 2. create a pingtest service which starts after network-online.target 3. We see initial ping loss Actual results: Network not accessible after reaching 'network-online.target' Expected results: Network accessible after reaching 'network-online.target' Additional info: ======================= # systemctl cat pingtest +++ # /etc/systemd/system/pingtest.service [Unit] Description=pingtest service Wants=network-online.target After=network-online.target [Service] Type=oneshot RemainAfterExit=yes ExecStart=/etc/init.d/ping-test.sh start [Install] WantedBy=default.target +++ # cat /etc/init.d/ping-test.sh +++ #!/bin/bash # # chkconfig: 35 90 12 # description: pingtest # # Get function from functions library . /etc/init.d/functions start() { printf "\n%s\n" "Start ping" count=10 while ! ping -c 1 -n -w 1 192.168.122.1 do printf "%c" "." if [[ $count < 1 ]] then exit else count=$(expr $count - 1) fi done printf "\n%s\n" "Server is online" } stop() { printf "\n%s\n" "Stop" } ### main logic ### case "$1" in start) start ;; stop) stop ;; restart|reload|condrestart) stop start ;; *) echo $"Usage: $0 {start|stop|restart|reload}" exit 1 esac exit 0 +++ ===== LOGS =========== //with team configured: May 12 23:55:26 localhost.localdomain NetworkManager[864]: <info> [1620878126.0069] manager: startup complete <--------------------------------- # journalctl -u pingtest -- Logs begin at Wed 2021-05-12 23:55:14 EDT, end at Thu 2021-05-13 00:00:23 EDT. -- May 12 23:55:26 localhost.localdomain systemd[1]: Starting description about this service... May 12 23:55:26 localhost.localdomain ping-test.sh[1182]: Start ping May 12 23:55:27 localhost.localdomain ping-test.sh[1182]: PING 192.168.122.1 (192.168.122.1) 56(84) bytes of data. May 12 23:55:27 localhost.localdomain ping-test.sh[1182]: --- 192.168.122.1 ping statistics --- May 12 23:55:27 localhost.localdomain ping-test.sh[1182]: 1 packets transmitted, 0 received, 100% packet loss, time 0ms May 12 23:55:28 localhost.localdomain ping-test.sh[1182]: .PING 192.168.122.1 (192.168.122.1) 56(84) bytes of data. May 12 23:55:28 localhost.localdomain ping-test.sh[1182]: --- 192.168.122.1 ping statistics --- May 12 23:55:28 localhost.localdomain ping-test.sh[1182]: 1 packets transmitted, 0 received, 100% packet loss, time 0ms May 12 23:55:29 localhost.localdomain ping-test.sh[1182]: .PING 192.168.122.1 (192.168.122.1) 56(84) bytes of data. May 12 23:55:29 localhost.localdomain ping-test.sh[1182]: --- 192.168.122.1 ping statistics --- May 12 23:55:29 localhost.localdomain ping-test.sh[1182]: 1 packets transmitted, 0 received, 100% packet loss, time 0ms May 12 23:55:29 localhost.localdomain ping-test.sh[1182]: .PING 192.168.122.1 (192.168.122.1) 56(84) bytes of data. May 12 23:55:29 localhost.localdomain ping-test.sh[1182]: From 192.168.122.174 icmp_seq=1 Destination Host Unreachable May 12 23:55:29 localhost.localdomain ping-test.sh[1182]: --- 192.168.122.1 ping statistics --- May 12 23:55:29 localhost.localdomain ping-test.sh[1182]: 1 packets transmitted, 0 received, +1 errors, 100% packet loss, time 0ms May 12 23:55:30 localhost.localdomain ping-test.sh[1182]: .PING 192.168.122.1 (192.168.122.1) 56(84) bytes of data. May 12 23:55:30 localhost.localdomain ping-test.sh[1182]: --- 192.168.122.1 ping statistics --- May 12 23:55:30 localhost.localdomain ping-test.sh[1182]: 1 packets transmitted, 0 received, 100% packet loss, time 0ms May 12 23:55:31 localhost.localdomain ping-test.sh[1182]: .PING 192.168.122.1 (192.168.122.1) 56(84) bytes of data. May 12 23:55:31 localhost.localdomain ping-test.sh[1182]: --- 192.168.122.1 ping statistics --- May 12 23:55:31 localhost.localdomain ping-test.sh[1182]: 1 packets transmitted, 0 received, 100% packet loss, time 0ms May 12 23:55:31 localhost.localdomain ping-test.sh[1182]: .PING 192.168.122.1 (192.168.122.1) 56(84) bytes of data. May 12 23:55:31 localhost.localdomain ping-test.sh[1182]: 64 bytes from 192.168.122.1: icmp_seq=1 ttl=64 time=33.9 ms <----------------------------- ping ok May 12 23:55:31 localhost.localdomain ping-test.sh[1182]: --- 192.168.122.1 ping statistics --- May 12 23:55:31 localhost.localdomain ping-test.sh[1182]: 1 packets transmitted, 1 received, 0% packet loss, time 0ms May 12 23:55:31 localhost.localdomain ping-test.sh[1182]: rtt min/avg/max/mdev = 33.887/33.887/33.887/0.000 ms May 12 23:55:31 localhost.localdomain ping-test.sh[1182]: Server is online //without team May 12 23:07:22 localhost NetworkManager[871]: <info> [1620875242.2569] manager: startup complete # journalctl -u pingtest May 12 23:07:22 localhost.localdomain systemd[1]: Starting description about this service... May 12 23:07:22 localhost.localdomain ping-test.sh[1147]: Start ping May 12 23:07:23 localhost.localdomain ping-test.sh[1147]: PING 192.168.122.1 (192.168.122.1) 56(84) bytes of data. May 12 23:07:23 localhost.localdomain ping-test.sh[1147]: 64 bytes from 192.168.122.1: icmp_seq=1 ttl=64 time=790 ms May 12 23:07:23 localhost.localdomain ping-test.sh[1147]: --- 192.168.122.1 ping statistics --- May 12 23:07:23 localhost.localdomain ping-test.sh[1147]: 1 packets transmitted, 1 received, 0% packet loss, time 0ms May 12 23:07:23 localhost.localdomain ping-test.sh[1147]: rtt min/avg/max/mdev = 789.545/789.545/789.545/0.000 ms May 12 23:07:23 localhost.localdomain ping-test.sh[1147]: Server is online //NetworkManager logs May 12 23:55:25 localhost.localdomain NetworkManager[864]: <info> [1620878125.3054] device (ens8): carrier: link connected May 12 23:55:25 localhost.localdomain NetworkManager[864]: <info> [1620878125.3532] device (ens9): carrier: link connected May 12 23:55:26 localhost.localdomain NetworkManager[864]: <info> [1620878126.0069] manager: startup complete May 12 23:55:25 localhost.localdomain NetworkManager[864]: <debug> [1620878125.8019] device[b0c31af60ba0793f] (ens9): carrier: link disconnected (deferring action for 6000 milliseconds) (id=144) May 12 23:55:25 localhost.localdomain NetworkManager[864]: <info> [1620878125.8080] device (team0): enslaved team port ens9 May 12 23:55:25 localhost.localdomain NetworkManager[864]: <info> [1620878125.8081] device (ens9): Activation: connection 'ens9' enslaved, continuing activation May 12 23:55:26 localhost.localdomain NetworkManager[864]: <info> [1620878126.0069] manager: startup complete <--------------------------------- May 12 23:55:27 localhost.localdomain NetworkManager[864]: <info> [1620878127.7409] device (ens8): carrier: link connected May 12 23:55:27 localhost.localdomain NetworkManager[864]: <debug> [1620878127.7409] device[a4c176d52b9c80f8] (ens8): carrier: link disconnected (canceling deferred action) (id=136) May 12 23:55:27 localhost.localdomain NetworkManager[864]: <trace> [1620878127.7411] ethtool[3]: ETHTOOL_GSET, ens8: success May 12 23:55:27 localhost.localdomain NetworkManager[864]: <debug> [1620878127.7411] device[a4c176d52b9c80f8] (ens8): remove_pending_action (0): 'carrier-wait' May 12 23:55:27 localhost.localdomain NetworkManager[864]: <trace> [1620878127.7412] device[8b0439e954aeccbe] (team0): master: add one slave 0x5564d27bfcf0/ens8 (already registered) May 12 23:55:27 localhost.localdomain NetworkManager[864]: <info> [1620878127.7412] device (team0): carrier: link connected May 12 23:55:27 localhost.localdomain NetworkManager[864]: <debug> [1620878127.7412] device[8b0439e954aeccbe] (team0): remove_pending_action (0): 'carrier-wait' May 12 23:55:27 localhost.localdomain teamd_team0[1144]: <port_list> May 12 23:55:27 localhost.localdomain NetworkManager[864]: <info> [1620878127.8043] device (ens9): carrier: link connected May 12 23:55:27 localhost.localdomain NetworkManager[864]: <debug> [1620878127.8043] device[b0c31af60ba0793f] (ens9): carrier: link disconnected (canceling deferred action) (id=144) May 12 23:55:27 localhost.localdomain NetworkManager[864]: <trace> [1620878127.8044] ethtool[4]: ETHTOOL_GSET, ens9: success May 12 23:55:27 localhost.localdomain NetworkManager[864]: <debug> [1620878127.8044] device[b0c31af60ba0793f] (ens9): remove_pending_action (0): 'carrier-wait' May 12 23:55:27 localhost.localdomain NetworkManager[864]: <trace> [1620878127.8045] device[8b0439e954aeccbe] (team0): master: add one slave 0x5564d27c4d60/ens9 (already registered) May 12 23:55:30 localhost.localdomain teamd_team0[1144]: ens8: ethtool-link went up. <------------------------------------------------- May 12 23:55:30 localhost.localdomain teamd_team0[1144]: Found best port: "ens8" (ifindex "3", prio "100"). May 12 23:55:30 localhost.localdomain teamd_team0[1144]: Changed active port to "ens8". <-------------------------------------------------- +++ Ping gets reply after 23:55:30 Hrs. <<<<< # systemctl list-dependencies --reverse NetworkManager-wait-online NetworkManager-wait-online.service ● └─network-online.target ● ├─dnf-makecache.timer ● ├─nfs-mountd.service ● ├─nfs-server.service ● ├─pingtest.service ● ├─rpc-statd-notify.service ● ├─rpc-statd.service ● └─rsyslog.service # systemctl status NetworkManager-wait-online ● NetworkManager-wait-online.service - Network Manager Wait Online Loaded: loaded (/usr/lib/systemd/system/NetworkManager-wait-online.service; enabled; vendor preset: disabled) Active: active (exited) since Thu 2021-05-13 00:37:24 EDT; 23min ago Docs: man:nm-online(1) Process: 897 ExecStart=/usr/bin/nm-online -s -q (code=exited, status=0/SUCCESS) Main PID: 897 (code=exited, status=0/SUCCESS) Tasks: 0 (limit: 4817) Memory: 0B CGroup: /system.slice/NetworkManager-wait-online.service May 13 00:37:20 localhost.localdomain systemd[1]: Starting Network Manager Wait Online... May 13 00:37:24 localhost.localdomain systemd[1]: Started Network Manager Wait Online.