[202205][dualtor][active-active] orchagent failed to set route nexthop to `tun0` after shutdown port #11737

lolyu · 2022-08-15T10:23:56Z

Description

As the titile, after shutdown a port in active-active cable type, orchagent failed to set the route nexthop to tun0.

Steps to reproduce the issue:

shut port Ethernet40 op to down:

# show mux config
SWITCH_NAME        PEER_TOR
-----------------  ----------
svcstr-7050-acs-2  10.1.0.33
port        state    ipv4             ipv6               cable_type     soc_ipv4
----------  -------  ---------------  -----------------  -------------  ---------------
Ethernet40  auto     192.168.0.20/32  fc02:1000::14/128  active-active  192.168.0.21/32
# config interface shut Ethernet40

verify the mux is standby

# show mux status
PORT        STATUS    SERVER_STATUS    HEALTH     HWSTATUS      LAST_SWITCHOVER_TIME
----------  --------  ---------------  ---------  ------------  ---------------------------
Ethernet40  standby   unknown          unhealthy  inconsistent

show the route to server IP 192.168.0.20

# show ip route 192.168.0.20
Routing entry for 192.168.0.0/21
  Known via "connected", distance 0, metric 0, best
  Last update 02:46:38 ago
  * directly connected, Vlan1000

Here are syslog snippets:

Aug 15 10:17:36.817235 svcstr-7050-acs-1 NOTICE swss#orchagent: :- setState: [Ethernet40] Set MUX state from active to standby
Aug 15 10:17:36.817586 svcstr-7050-acs-1 INFO swss#orchagent: :- stateStandby: Set state to Standby for Ethernet40
Aug 15 10:17:36.817731 svcstr-7050-acs-1 INFO swss#orchagent: :- disable: Disabling neigh 192.168.0.20 on Vlan1000
Aug 15 10:17:36.817872 svcstr-7050-acs-1 INFO swss#orchagent: :- updateNextHopRoutes: No routes found for NH 192.168.0.20
Aug 15 10:17:36.817902 svcstr-7050-acs-1 NOTICE swss#orchagent: :- disableNeighbor: Neighbor disable request for 192.168.0.20
Aug 15 10:17:36.819871 svcstr-7050-acs-1 NOTICE swss#orchagent: :- removeNeighbor: Removed next hop 192.168.0.20 on Vlan1000
Aug 15 10:17:36.822460 svcstr-7050-acs-1 NOTICE swss#orchagent: :- removeNeighbor: Removed neighbor 92:b7:e8:b4:f2:0a on Vlan1000
Aug 15 10:17:36.822460 svcstr-7050-acs-1 INFO swss#orchagent: :- addTunnelRoute: Add tunnel route DB 'Vlan1000:192.168.0.20/32'
Aug 15 10:17:36.829733 svcstr-7050-acs-1 NOTICE swss#orchagent: :- create_route: Created tunnel route to 192.168.0.20/32
Aug 15 10:17:36.830002 svcstr-7050-acs-1 NOTICE swss#orchagent: :- MuxAclHandler: Binding port 100000000000c
...
Aug 15 10:17:45.077307 svcstr-7050-acs-1 INFO swss#orchagent: message repeated 5 times: [ :- set: setting attribute 0x10000004 status: SAI_STATUS_SUCCESS]
Aug 15 10:17:45.077307 svcstr-7050-acs-1 NOTICE swss#orchagent: :- removeNeighbor: Removed neighbor 92:b7:e8:b4:f2:0a on Vlan1000
Aug 15 10:17:45.077307 svcstr-7050-acs-1 INFO swss#orchagent: :- update: Neigh 192.168.0.20 on Vlan1000, add 0, state 2
Aug 15 10:17:45.123468 svcstr-7050-acs-1 NOTICE swss#orchagent: :- remove_route: Removed tunnel route to 192.168.0.20/32
Aug 15 10:17:45.123468 svcstr-7050-acs-1 INFO swss#orchagent: :- removeTunnelRoute: Remove tunnel route DB 'Vlan1000:192.168.0.20/32'
Aug 15 10:17:45.142889 svcstr-7050-acs-1 INFO swss#orchagent: :- removeRoute: Failed to find route entry, vrf_id 0x3000000000024, prefix 192.168.0.20/32
Aug 15 10:17:45.573609 svcstr-7050-acs-1 INFO swss#orchagent: :- set: setting attribute 0x10000004 status: SAI_STATUS_SUCCESS

Compared with ports in active-standby, the second syslog chunk is showed only with active-active ports. It looks like that the neighbor is removed twice.

Describe the results you received:

the nexthop to server 192.168.0.20 is still Vlan1000 when the port Ethernet40 is standby

Describe the results you expected:

the nexthop to server 192.168.0.20 should be tun0

Output of `show version`:

# show version

SONiC Software Version: SONiC.20220531.03
Distribution: Debian 11.4
Kernel: 5.10.0-12-2-amd64
Build commit: 9b08c30e8d
Build date: Sat Aug 13 18:53:03 UTC 2022
Built by: cloudtest@3a9a2794c00000E```
#### Output of `show techsupport`:

(paste your output here or download and attach the file here )


#### Additional information you deem important (e.g. issue happens only occasionally):

<!--
     Also attach debug file produced by `sudo generate_dump`
-->

The text was updated successfully, but these errors were encountered:

lolyu · 2022-08-15T10:24:44Z

Hi @prsunny, could you please take a look into this issue?

prsunny · 2022-08-16T00:19:45Z

@lolyu , is this happening for all neighbors? Also, is tunnel/mux_cable created during initialization or you manually added those?

lolyu · 2022-08-16T01:21:38Z

@lolyu , is this happening for all neighbors? Also, is tunnel/mux_cable created during initialization or you manually added those?

Hi @prsunny, the neighbors are advertised by garp_service, it should be happening for all neighbors, let me check further.

lolyu · 2022-08-17T03:32:06Z

Hi @prsunny, I've found that, for those ports that have this issue, after shutdown the port, the neighbor entry state changes to FAILED in a short period of time(3~10s) or so.
For example:

shutdown port Ethernet12:

# config interface shutdown Ethernet20

verify the kernel neighbor entry learned from Ethernet12:

# ip neighbor | grep 192.168.0.10
192.168.0.10 dev Vlan1000 lladdr 36:fe:61:4c:e4:05 DELAY
# ip neighbor | grep 192.168.0.10
192.168.0.10 dev Vlan1000 lladdr 36:fe:61:4c:e4:05 DELAY
# ip neighbor | grep 192.168.0.10
192.168.0.10 dev Vlan1000 lladdr 36:fe:61:4c:e4:05 DELAY
# ip neighbor | grep 192.168.0.10
192.168.0.10 dev Vlan1000 lladdr 36:fe:61:4c:e4:05 DELAY
# ip neighbor | grep 192.168.0.10
192.168.0.10 dev Vlan1000 lladdr 36:fe:61:4c:e4:05 PROBE
# ip neighbor | grep 192.168.0.10
192.168.0.10 dev Vlan1000 lladdr 36:fe:61:4c:e4:05 PROBE
# ip neighbor | grep 192.168.0.10
192.168.0.10 dev Vlan1000  FAILED

lolyu · 2022-08-17T07:07:07Z

I think I've found the root cause for this, the neighbors for the mux servers are not validated by the kernel into state REACHABLE.

For those neighbors of mux servers that are STALE, if we shutdown the port, the route to the neighbor will be changed to tun0, but the route will be removed and changed back to Vlan1000 when the neighbor comes to FAILED:

# ip neighbor | grep 192.168.0.2
192.168.0.2 dev Vlan1000 lladdr 46:4f:0d:81:e8:01 STALE
# config interface shutdown Ethernet4
# show ip route 192.168.0.2
Routing entry for 192.168.0.0/21
  Known via "connected", distance 0, metric 0, best
  Last update 22:29:11 ago
  * directly connected, Vlan1000

# ip neighbor | grep 192.168.0.2
192.168.0.2 dev Vlan1000  FAILED

For those neighbors of mux servers that are REACHABLE, the route to the neighbor could be changed to tun0:

root@svcstr-7050-acs-1:~# ip neighbor | grep 192.168.0.4
192.168.0.4 dev Vlan1000 lladdr 06:a8:be:16:05:02 REACHABLE
root@svcstr-7050-acs-1:~# config interface shutdown Ethernet8
root@svcstr-7050-acs-1:~# ip neighbor | grep 192.168.0.4
192.168.0.4 dev Vlan1000 lladdr 06:a8:be:16:05:02 REACHABLE
root@svcstr-7050-acs-1:~# show ip route 192.168.0.4
Routing entry for 192.168.0.4/32
  Known via "kernel", distance 0, metric 0, best
  Last update 00:00:19 ago
  * directly connected, tun0

I assume we should ensure that the neighbors for mux servers are REACHABLE before any dualtor IO testcases. But currently, the neighbors learned from gratuitous ARP(garp_service) are all in STALE state, so some of the link down downstream dualtor IO testcases suffer from this issue. So I will post some changes to probe those neighbors with arp_responder on to ensure those neighbors are all in REACHABLE state, is this proposal OK to you? @prsunny

lolyu · 2022-08-18T01:23:56Z

Discussed with @prsunny, this issue should be fixed by PR: sonic-net/sonic-swss#2151, let's cherry-pick those testcases into 202205/master branch, thanks!

…ve (#6174) Approach What is the motivation for this PR? Enable test_active_link_down_downstream_active for active-active dualtor. Signed-off-by: Longxiang Lyu lolv@microsoft.com How did you do it? due to sonic-net/sonic-buildimage#11737, before IO verification, add method _probe_stale_servers to ensure all STALE neighbors of mux servers that are learned from garp_service are changed into REACHABLE state. How did you verify/test it?

lolyu · 2022-08-23T14:26:32Z

Close this as PR sonic-net/sonic-swss#2151 got merged.

lolyu · 2022-08-23T14:27:24Z

Will try to verify on the latest image for the change: sonic-net/sonic-swss#2151

lolyu · 2022-09-01T03:13:32Z

Verified on the latest 202205 image, the issue is gone, now the route to tun0 could be persistent with neighbor entry changes to FAILED state.

…ve (sonic-net#6174) Approach What is the motivation for this PR? Enable test_active_link_down_downstream_active for active-active dualtor. Signed-off-by: Longxiang Lyu lolv@microsoft.com How did you do it? due to sonic-net/sonic-buildimage#11737, before IO verification, add method _probe_stale_servers to ensure all STALE neighbors of mux servers that are learned from garp_service are changed into REACHABLE state. How did you verify/test it?

lolyu mentioned this issue Aug 16, 2022

[dualtor][active-active] Enable test_active_link_down_downstream_active sonic-net/sonic-mgmt#6174

Merged

5 tasks

zhangyanzhao assigned zhangyanzhao, prsunny and lolyu and unassigned zhangyanzhao and prsunny Aug 17, 2022

zhangyanzhao added the Triaged this issue has been triaged label Aug 17, 2022

lolyu changed the title ~~[dualtor][active-active] orchagent failed to set route nexthop to tun0 after shutdown port~~ [202205][dualtor][active-active] orchagent failed to set route nexthop to tun0 after shutdown port Aug 18, 2022

lolyu closed this as completed Aug 23, 2022

lolyu reopened this Aug 23, 2022

lolyu closed this as completed Sep 1, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[202205][dualtor][active-active] orchagent failed to set route nexthop to `tun0` after shutdown port #11737

[202205][dualtor][active-active] orchagent failed to set route nexthop to `tun0` after shutdown port #11737

lolyu commented Aug 15, 2022 •

edited

Loading

lolyu commented Aug 15, 2022

prsunny commented Aug 16, 2022

lolyu commented Aug 16, 2022 •

edited

Loading

lolyu commented Aug 17, 2022

lolyu commented Aug 17, 2022 •

edited

Loading

lolyu commented Aug 18, 2022 •

edited

Loading

lolyu commented Aug 23, 2022

lolyu commented Aug 23, 2022 •

edited

Loading

lolyu commented Sep 1, 2022

[202205][dualtor][active-active] orchagent failed to set route nexthop to tun0 after shutdown port #11737

[202205][dualtor][active-active] orchagent failed to set route nexthop to tun0 after shutdown port #11737

Comments

lolyu commented Aug 15, 2022 • edited Loading

Description

Steps to reproduce the issue:

Describe the results you received:

Describe the results you expected:

Output of show version:

lolyu commented Aug 15, 2022

prsunny commented Aug 16, 2022

lolyu commented Aug 16, 2022 • edited Loading

lolyu commented Aug 17, 2022

lolyu commented Aug 17, 2022 • edited Loading

lolyu commented Aug 18, 2022 • edited Loading

lolyu commented Aug 23, 2022

lolyu commented Aug 23, 2022 • edited Loading

lolyu commented Sep 1, 2022

[202205][dualtor][active-active] orchagent failed to set route nexthop to `tun0` after shutdown port #11737

[202205][dualtor][active-active] orchagent failed to set route nexthop to `tun0` after shutdown port #11737

lolyu commented Aug 15, 2022 •

edited

Loading

Output of `show version`:

lolyu commented Aug 16, 2022 •

edited

Loading

lolyu commented Aug 17, 2022 •

edited

Loading

lolyu commented Aug 18, 2022 •

edited

Loading

lolyu commented Aug 23, 2022 •

edited

Loading