The orchagent will be crashed after portchannel infterfaces up/down several times

[kaiyu22]

Description:
We do the test to verify the link status of portchannel interfaces on DUT. We shutdown/no shutdown the interfaces of fanout switch and observe the link status of portchannel interfaces on DUT.

The topology is simular to MSFT's testbed, in which the following is the interface information:

 DUT Portchannel0       Fanout switch
 Ethernet0 -----------  Interface 3
 Ethernet4 -----------  Interface 4
 .... (skip)

Reproduce steps:
1. Shutdown interface 3 of fanout switch
2. Input bcmcmd "ps" on DUT and observe the link status
3. No shutdown interface 3 of fanout switch
4. Input bcmcmd "ps" on DUT and observe the link status
5. Take a break around 20 seconds
6. Repeat step 1 to 5 several times
7. If issue happens, the orchagent will be terminated and status of bcmcmd "ps" won't update

Test image version:
We have tested two commitments "b6efe43" and "116ba4b", and both of them have this issue.

Test information:

root@sonic:/home/admin# show ver
SONiC Software Version: SONiC.SONiC-Ingrasys-20170907-116ba4b
Distribution: Debian 8.9
Kernel: 3.16.0-4-amd64
Build commit: 116ba4b
Build date: Thu Sep  7 17:02:06 UTC 2017
Built by: sonic@debian

Docker images:
REPOSITORY                TAG                 IMAGE ID            SIZE
docker-syncd-brcm         latest              ef4f137855e2        318.5 MB
docker-orchagent-brcm     latest              8a50662f894d        258.5 MB
docker-lldp-sv2           latest              9c3be667f967        256.7 MB
docker-dhcp-relay         latest              a63a2e7d63d0        253.6 MB
docker-database           latest              81b09d914a1d        251.8 MB
docker-snmp-sv2           latest              132ed59ee781        291.4 MB
docker-teamd              latest              2063afbf01b6        255.5 MB
docker-platform-monitor   latest              3a9763be5e0c        271.1 MB
docker-fpm-quagga         latest              e653769681bb        262.1 MB

root@sonic:/home/admin# show platform sum
Platform: x86_64-ingrasys_s9100-r0
HwSKU: INGRASYS-S9100-C32
ASIC: broadcom

The syslog in DUT:

...
Sep  1 03:16:40.0 sonic NOTICE orchagent: :- addNeighbor: Created neighbor 52:54:00:8e:56:47 on Ethernet124
Sep  1 03:16:40.0 sonic NOTICE orchagent: :- addNextHop: Created next hop fc00::7e on Ethernet124
Sep  1 03:16:42.0 sonic NOTICE orchagent: :- addNeighbor: Created neighbor 52:54:00:79:a8:6d on Ethernet64
Sep  1 03:16:42.0 sonic NOTICE orchagent: :- addNextHop: Created next hop fc00::42 on Ethernet64
Sep  1 03:16:42.0 sonic NOTICE orchagent: :- addNeighbor: Created neighbor 52:54:00:aa:7a:e8 on Ethernet92
Sep  1 03:16:42.0 sonic NOTICE orchagent: :- addNextHop: Created next hop fc00::5e on Ethernet92
Sep  1 03:16:42.0 sonic NOTICE orchagent: :- addNeighbor: Created neighbor 52:54:00:a7:5a:e6 on Ethernet108
Sep  1 03:16:42.0 sonic NOTICE orchagent: :- addNextHop: Created next hop fc00::6e on Ethernet108
Sep  1 03:16:44.0 sonic NOTICE orchagent: :- addNeighbor: Created neighbor 52:54:00:83:0e:1e on Ethernet120
Sep  1 03:16:44.0 sonic NOTICE orchagent: :- addNextHop: Created next hop fc00::7a on Ethernet120
Sep  1 03:16:46.0 sonic NOTICE orchagent: :- addNeighbor: Created neighbor 52:54:00:dd:85:74 on Ethernet80
Sep  1 03:16:46.0 sonic NOTICE orchagent: :- addNextHop: Created next hop fc00::52 on Ethernet80
Sep  1 03:16:54.0 sonic NOTICE orchagent: :- on_port_state_change: Get port state change notification id:100000000001f status:2
Sep  1 03:16:54.0 sonic NOTICE orchagent: :- setHostIntfsOperStatus: Set operation status DOWN to host interface Ethernet64
Sep  1 03:16:54.0 sonic NOTICE orchagent: :- doPortTask: Set port Ethernet64 admin status to up
Sep  1 03:16:54.0 sonic NOTICE orchagent: :- doPortTask: Set port Ethernet64 MTU to 9216
Sep  1 03:16:59.0 sonic NOTICE orchagent: :- on_port_state_change: Get port state change notification id:100000000001f status:1
Sep  1 03:16:59.0 sonic NOTICE orchagent: :- setHostIntfsOperStatus: Set operation status UP to host interface Ethernet64
Sep  1 03:16:59.0 sonic NOTICE orchagent: :- doPortTask: Set port Ethernet64 admin status to up
Sep  1 03:16:59.0 sonic NOTICE orchagent: :- doPortTask: Set port Ethernet64 MTU to 9216
Sep  1 03:25:41.0 sonic NOTICE orchagent: :- on_port_state_change: Get port state change notification id:1000000000019 status:2
Sep  1 03:25:41.0 sonic NOTICE orchagent: :- setHostIntfsOperStatus: Set operation status DOWN to host interface Ethernet0
Sep  1 03:25:41.0 sonic NOTICE orchagent: :- doPortTask: Set port Ethernet0 admin status to up
Sep  1 03:25:41.0 sonic NOTICE orchagent: :- doPortTask: Set port Ethernet0 MTU to 9216
Sep  1 03:25:41.0 sonic NOTICE orchagent: :- removeLagMember: Remove member Ethernet0 from LAG PortChannel0 lid:2000000000588 lmid:1a00000000058a
Sep  1 03:25:42.0 sonic NOTICE orchagent: :- addNextHopGroup: Create next hop group nhgid:50000000005ed nh:10.0.0.5,10.0.0.9,10.0.0.13,10.0.0.17,10.0.0.21,10.0.0.25,10.0.0.29
Sep  1 03:25:44.0 sonic NOTICE orchagent: :- addNextHopGroup: Create next hop group nhgid:50000000005ee nh:fc00::a,fc00::12,fc00::1a,fc00::22,fc00::2a,fc00::32,fc00::3a
Sep  1 03:25:47.0 sonic ERR orchagent: :- meta_generic_validation_remove: object 0x50000000005d8 reference count is 1, can't remove
Sep  1 03:25:47.0 sonic ERR orchagent: :- removeNextHopGroup: Failed to remove next hop group nhgid:50000000005d8
Sep  1 03:25:51.0 sonic NOTICE orchagent: :- removeNeighbor: Removed next hop fc00::2 on PortChannel0
Sep  1 03:25:51.0 sonic NOTICE orchagent: :- removeNeighbor: Removed neighbor 52:54:00:d2:8f:2f on PortChannel0
Sep  1 03:25:56.0 sonic ERR syncd: brcm_sai_remove_next_hop:373 L3 egress destroy failed with error Operation still running (0xfffffff6).
Sep  1 03:25:56.0 sonic ERR syncd: :- processEvent: failed to execute api: remove, key: SAI_OBJECT_TYPE_NEXT_HOP:oid:0x40000000005b4, status: SAI_STATUS_OBJECT_IN_USE
Sep  1 03:25:56.0 sonic NOTICE orchagent: :- handle_switch_shutdown_request: switch shutdown request
Sep  1 03:25:56.0 sonic ERR orchagent: :- on_switch_shutdown_request: Syncd stopped
Sep  1 03:25:56.0 sonic INFO supervisord: orchagent terminate called without an active exception
Sep  1 03:25:56.0 sonic NOTICE syncd: :- exit_and_notify: sending switch_shutdown_request notification to OA
Sep  1 03:25:56.0 sonic NOTICE syncd: :- exit_and_notify: notification send successfull
Sep  1 03:25:56.0 sonic WARNING syncd: :- exit_and_notify: sleep forever to keep data plane active
Sep  1 03:25:57.489931 sonic INFO swss.sh[1873]: 2017-09-01 03:25:57,489 INFO exited: orchagent (terminated by SIGABRT (core dumped); not expected)

[kaiyu22]

BTW, the DUT is deployed as t1-lag minigraph.

[stcheng]

Hello @kaiyu22 could you provide the platform and the version of the image you run the test against?

[kaiyu22]

Hi @stcheng, I have updated the platform and version in the original posted.

[kaiyu22]

Hi @stcheng , @maggiemsft, does this issue pass or fail in your testbed?

[maggiemsft]

Hi @kaiyu22, if you don't use bcmcmd ps to check the link status, will it still crash?
you may try 'ip link show' to monitor the link status.
I think this is due to bcmcmd ps command is low leval api call and it may have some conflict/race condition when orchagent's action?

[kaiyu22]

Hi @maggiemsft,

1. It doesn't need to input command "bcmcmd ps", the orchagent will still crash. The error message is the same in syslog.
2. BTW, you can use "ansible/roles/test/tasks/lag_2.yml" to verify this case. This test is equal to one of test case of lag_2.yml.

[stcheng]

Hello @kaiyu22 , what's the chip model?
I confirm that we saw this issue as well. But it doesn't occur on Trident II platform.

[kaiyu22]

Hi @stcheng, the chip model is Tomahawk.

[stcheng]

Hello @kaiyu22 yes I verified that it is a SAI implementation bug that appears in TH/TH2 platforms. We will evaluate the fix soon.