Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

unplug/shutdown mclag member interface crash mclag and related containers #2913

Open
ccy opened this issue Sep 21, 2023 · 1 comment
Open

unplug/shutdown mclag member interface crash mclag and related containers #2913

ccy opened this issue Sep 21, 2023 · 1 comment

Comments

@ccy
Copy link

ccy commented Sep 21, 2023 •
edited
Loading

I am trying mclag with 2 mellanox SN2410 switch. I build the sonic firmware using master branch of sonic-buildimage with INCLUDE_ICCPD = y.

Switch 1 mclag configuration:

# Enable iccpd feature
config feature state iccpd enabled

# Peer link: Port Channel
config portchannel add PortChannel2001
config portchannel member add PortChannel2001 Ethernet192
config portchannel member add PortChannel2001 Ethernet196
config switchport mode trunk PortChannel2001

# Peer Link: VLAN
config vlan add 10
config vlan member add 10 PortChannel2001

# MCLAG domain
config mclag add 1 192.168.10.1 192.168.10.2 PortChannel2001
config mclag unique-ip add Vlan10
config interface ip add Vlan10 192.168.10.1/24

config vlan add 100
config mclag unique-ip add Vlan100
config vlan member add 100 PortChannel2001
config interface ip add Vlan100 192.168.100.1/24

# Create mlag port channel interface
ID=184
config portchannel add PortChannel$ID
config portchannel member add PortChannel$ID Ethernet$ID
config switchport mode trunk PortChannel$ID
config mclag member add 1 PortChannel$ID
config vlan member add 100 PortChannel$ID

Switch 2 mclag configuration:

# Enable iccpd feature
config feature state iccpd enabled

# Peer link: Port Channel
config portchannel add PortChannel2001
config portchannel member add PortChannel2001 Ethernet192
config portchannel member add PortChannel2001 Ethernet196
config switchport mode trunk PortChannel2001

# Peer Link: VLAN
config vlan add 10
config vlan member add 10 PortChannel2001

# MCLAG domain
config mclag add 1 192.168.10.2 192.168.10.1 PortChannel2001
config mclag unique-ip add Vlan10
config interface ip add Vlan10 192.168.10.2/24

config vlan add 100
config mclag unique-ip add Vlan100
config vlan member add 100 PortChannel2001
config interface ip add Vlan100 192.168.100.2/24

# Create mlag port channel interface
ID=184
config portchannel add PortChannel$ID
config portchannel member add PortChannel$ID Ethernet$ID
config switchport mode trunk PortChannel$ID
config mclag member add 1 PortChannel$ID
config vlan member add 100 PortChannel$ID

Runtime information for switch 1:

$ show int portchannel
Flags: A - active, I - inactive, Up - up, Dw - Down, N/A - not available,
       S - selected, D - deselected, * - not synced
  No.  Team Dev         Protocol     Ports
-----  ---------------  -----------  -----------------------------
  184  PortChannel184   LACP(A)(Up)  Ethernet184(S)
 2001  PortChannel2001  LACP(A)(Up)  Ethernet192(S) Ethernet196(S)

$ mclagdctl dump state
The MCLAG's keepalive is: OK
MCLAG info sync is: completed
Domain id: 1
Local Ip: 192.168.10.1
Peer Ip: 192.168.10.2
Peer Link Interface: PortChannel2001
Keepalive time: 1
sesssion Timeout : 15
Peer Link Mac: 04:3f:72:2f:38:00
Role: Active
MCLAG Interface: PortChannel184
Loglevel: NOTICE

$ mclagdctl dump mac -i 1
TYPE: S-STATIC, D-DYNAMIC; AGE: L-Local age, P-Peer age
No.   TYPE MAC                 VID  DEV                 ORIGIN-DEV          AGE
1     S    50:6b:4b:9b:82:c0   10   PortChannel2001     PortChannel2001     L
2     S    50:6b:4b:9b:82:c0   100  PortChannel2001     PortChannel2001     L
3     D    64:9d:99:17:cb:2c   100  PortChannel184      PortChannel184      P

$ show vlan brief
+-----------+------------------+-----------------+----------------+-------------+-----------------------+
|   VLAN ID | IP Address       | Ports           | Port Tagging   | Proxy ARP   | DHCP Helper Address   |
+===========+==================+=================+================+=============+=======================+
|        10 | 192.168.10.1/24  | PortChannel2001 | tagged         | disabled    |                       |
+-----------+------------------+-----------------+----------------+-------------+-----------------------+
|       100 | 192.168.100.1/24 | PortChannel184  | tagged         | disabled    |                       |
|           |                  | PortChannel2001 | tagged         |             |                       |
+-----------+------------------+-----------------+----------------+-------------+-----------------------+

$ show mac
  No.    Vlan  MacAddress         Port             Type
-----  ------  -----------------  ---------------  -------
    1      10  50:6B:4B:9B:82:C0  PortChannel2001  Static
    2     100  64:9D:99:17:CB:2C  PortChannel184   Dynamic
    3     100  50:6B:4B:9B:82:C0  PortChannel2001  Static

Runtime information for switch 2

$ show int portchannel
Flags: A - active, I - inactive, Up - up, Dw - Down, N/A - not available,
       S - selected, D - deselected, * - not synced
  No.  Team Dev         Protocol     Ports
-----  ---------------  -----------  -----------------------------
  176  PortChannel176   LACP(A)(Dw)  Ethernet176(S*)
  184  PortChannel184   LACP(A)(Up)  Ethernet184(S)
 2001  PortChannel2001  LACP(A)(Up)  Ethernet196(S) Ethernet192(S)

$ mclagdctl dump state
The MCLAG's keepalive is: OK
MCLAG info sync is: completed
Domain id: 1
Local Ip: 192.168.10.2
Peer Ip: 192.168.10.1
Peer Link Interface: PortChannel2001
Keepalive time: 1
sesssion Timeout : 15
Peer Link Mac: 50:6b:4b:9b:82:c0
Role: Standby
MCLAG Interface: PortChannel184
Loglevel: NOTICE

$ mclagdctl dump mac -i 1
TYPE: S-STATIC, D-DYNAMIC; AGE: L-Local age, P-Peer age
No.   TYPE MAC                 VID  DEV                 ORIGIN-DEV          AGE
1     S    04:3f:72:2f:38:00   10   PortChannel2001     PortChannel2001     L
2     S    04:3f:72:2f:38:00   100  PortChannel2001     PortChannel2001     L
3     D    64:9d:99:17:cb:2c   100  PortChannel184      PortChannel184      L

$ show vlan brief
+-----------+------------------+-----------------+----------------+-------------+-----------------------+
|   VLAN ID | IP Address       | Ports           | Port Tagging   | Proxy ARP   | DHCP Helper Address   |
+===========+==================+=================+================+=============+=======================+
|        10 | 192.168.10.2/24  | PortChannel2001 | tagged         | disabled    |                       |
+-----------+------------------+-----------------+----------------+-------------+-----------------------+
|       100 | 192.168.100.2/24 | PortChannel184  | tagged         | disabled    |                       |
|           |                  | PortChannel2001 | tagged         |             |                       |
+-----------+------------------+-----------------+----------------+-------------+-----------------------+

$ show mac
  No.    Vlan  MacAddress         Port             Type
-----  ------  -----------------  ---------------  ------
    1      10  04:3F:72:2F:38:00  PortChannel2001  Static
    2     100  04:3F:72:2F:38:00  PortChannel2001  Static
    3     100  64:9D:99:17:CB:2C  PortChannel184   Static
Total number of entries 3

Above states show switch-1 role is Active and switch-2 role is Standby. I assume my mc-lag configuration is correct at this moment.

Next I try to shutdown interface Ethernet184 of switch-2:

config int shutdown Ethernet184

After a while, few docker container crash and restarted. The mclag peering connections crash too. Those crash container/service will back online after some time.

This is the log captured during the crashing:


Sep 21 12:44:49.392405 sonic WARNING swss#orchagent: :- parsePortConfig: Unknown field(mode): skipping ...
Sep 21 12:44:49.392405 sonic INFO lldp#lldpmgrd[36]: Unable to retrieve description for port 'Ethernet184'. Not adding port description
Sep 21 12:44:49.398965 sonic NOTICE swss#portmgrd: :- doTask: Configure Ethernet184 MTU to 9100
Sep 21 12:44:49.406885 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_newlink.NOTICE] Update local port Ethernet184 state down
Sep 21 12:44:49.406885 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_deladdr.NOTICE] l3_proto 0, ifname Ethernet184 index 1689 is_vrf 0 address fe80::63f:72ff:fe2f:3800
Sep 21 12:44:49.406885 sonic NOTICE swss#portsyncd: :- onMsg: nlmsg type:16 key:Ethernet184 admin:0 oper:0 addr:04:3f:72:2f:38:00 ifindex:1689 master:1601 type:sx_netdev
Sep 21 12:44:49.406885 sonic NOTICE swss#portmgrd: :- doTask: Configure Ethernet184 admin status to down
Sep 21 12:44:49.406885 sonic NOTICE swss#portsyncd: :- onMsg: Publish Ethernet184(ok:down) to state db
Sep 21 12:44:49.406885 sonic NOTICE swss#portsyncd: :- onMsg: nlmsg type:16 key:Ethernet184 admin:0 oper:0 addr:04:3f:72:2f:38:00 ifindex:1689 master:1601 type:sx_netdev
Sep 21 12:44:49.415814 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_newlink.NOTICE] Update local port PortChannel184 state down
Sep 21 12:44:49.416580 sonic INFO kernel: [94358.277233] Bridge: port 3(PortChannel184) entered disabled state
Sep 21 12:44:49.424011 sonic WARNING swss#orchagent: message repeated 2 times: [ :- parsePortConfig: Unknown field(mode): skipping ...]
Sep 21 12:44:49.424011 sonic NOTICE swss#orchagent: :- setPortAdminStatus: Set admin status DOWN host_tx_ready to false for port Ethernet184
Sep 21 12:44:49.424011 sonic NOTICE iccpd#mclagsyncd: :- setFdbEntry: add fdb entry into ASIC_DB:key =Vlan100:64:9d:99:17:cb:2c, type =dynamic
Sep 21 12:44:49.431302 sonic NOTICE swss#portsyncd: :- onMsg: Publish Ethernet184(ok:down) to state db
Sep 21 12:44:49.431302 sonic NOTICE swss#portsyncd: :- onMsg: nlmsg type:16 key:Ethernet184 admin:0 oper:0 addr:04:3f:72:2f:38:00 ifindex:1689 master:1601 type:sx_netdev
Sep 21 12:44:49.431302 sonic NOTICE iccpd#mclagsyncd: :- mclagsyncdSetTrafficDisable: Set traffic disable for PortChannel184
Sep 21 12:44:49.431302 sonic NOTICE syncd#SDK: [SAI_UTILS.NOTICE] ./src/mlnx_sai_utils.c[1911]- set_dispatch_attrib_handler: Set ADMIN_STATE, key:PORT [OID:0x1000F00000001] [log_port:0x1000F], val:false
Sep 21 12:44:49.437820 sonic NOTICE swss#portsyncd: :- onMsg: Publish Ethernet184(ok:down) to state db
Sep 21 12:44:49.437820 sonic NOTICE syncd#SDK: [SAI_SWITCH.NOTICE] ./src/mlnx_sai_switch.c[6689]- event_thread_func: Port 1000f changed state to down
Sep 21 12:44:49.437820 sonic NOTICE swss#portsyncd: :- onMsg: nlmsg type:16 key:PortChannel184 admin:1 oper:0 addr:04:3f:72:2f:38:00 ifindex:1601 master:1578
Sep 21 12:44:49.437820 sonic NOTICE swss#portsyncd: :- onMsg: Cannot find PortChannel184 in port table
Sep 21 12:44:49.437820 sonic NOTICE swss#portsyncd: :- onMsg: nlmsg type:16 key:PortChannel184 admin:1 oper:0 addr:04:3f:72:2f:38:00 ifindex:1601 master:1578 type:team
Sep 21 12:44:49.440725 sonic NOTICE kernel: [94358.300817] Called for logical port - 1000F status DOWN
Sep 21 12:44:49.441977 sonic NOTICE bgp#fpmsyncd: message repeated 2 times: [ :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fe80::/64 :: eth0 ]
Sep 21 12:44:49.441977 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: 0.0.0.0/0 192.168.0.1 eth0
Sep 21 12:44:49.441977 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: ::/0 fe80::21b:21ff:febe:2f0 eth0
Sep 21 12:44:49.441977 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fd00::/80 :: docker0
Sep 21 12:44:49.441977 sonic NOTICE swss#orchagent: :- doPortTask: Set port Ethernet184 admin status to down
Sep 21 12:44:49.441977 sonic NOTICE swss#orchagent: :- doTask: Get port state change notification id:1000000000408 status:2
Sep 21 12:44:49.441977 sonic NOTICE swss#orchagent: :- updatePortOperStatus: Port Ethernet184 oper state set from up to down
Sep 21 12:44:49.441977 sonic NOTICE syncd#SDK: [SAI_UTILS.NOTICE] ./src/mlnx_sai_utils.c[1911]- set_dispatch_attrib_handler: Set OPER_STATUS, key:HOSTIF [OID:0x2E0000000D] [hostif_db[46]], val:false
Sep 21 12:44:49.446311 sonic INFO lldp#lldpmgrd[36]: Unable to retrieve description for port 'Ethernet184'. Not adding port description
Sep 21 12:44:49.446311 sonic INFO lldp#lldpmgrd[36]: port Ethernet184 is not up, continue
Sep 21 12:44:49.446311 sonic INFO lldp#lldpmgrd[36]: Unable to retrieve description for port 'Ethernet184'. Not adding port description
Sep 21 12:44:49.452424 sonic INFO lldp#lldpmgrd[36]: port Ethernet184 is not up, continue
Sep 21 12:44:49.452651 sonic INFO lldp#lldpmgrd[36]: Unable to retrieve description for port 'Ethernet184'. Not adding port description
Sep 21 12:44:49.452827 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fe80::/64 :: eth0
Sep 21 12:44:49.453029 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: 0.0.0.0/0 192.168.0.1 eth0
Sep 21 12:44:49.453185 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: ::/0 fe80::21b:21ff:febe:2f0 eth0
Sep 21 12:44:49.453354 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fd00::/80 :: docker0
Sep 21 12:44:49.461411 sonic NOTICE swss#orchagent: :- setHostIntfsOperStatus: Set operation status DOWN to host interface Ethernet184
Sep 21 12:44:49.461411 sonic NOTICE swss#orchagent: :- publish: EVENT_PUBLISHED: {"sonic-events-swss:if-state":{"ifname":"Ethernet184","status":"down","timestamp":"2023-09-21T12:44:49.450308Z"}}
Sep 21 12:44:49.461411 sonic WARNING swss#orchagent: :- flushFDBEntries: Couldn't flush FDB. Bridge port OID: 0x0 bvid:0,
Sep 21 12:44:49.461411 sonic INFO lldp#lldpmgrd[36]: port Ethernet184 is not up, continue
Sep 21 12:44:49.461411 sonic INFO lldp#lldpmgrd[36]: Unable to retrieve description for port 'Ethernet184'. Not adding port description
Sep 21 12:44:49.461411 sonic INFO lldp#lldpmgrd[36]: port Ethernet184 is not up, continue
Sep 21 12:44:49.461411 sonic INFO lldp#lldpmgrd[36]: Unable to retrieve description for port 'Ethernet184'. Not adding port description
Sep 21 12:44:49.461411 sonic INFO lldp#lldpmgrd[36]: port Ethernet184 is not up, continue
Sep 21 12:44:49.461411 sonic NOTICE syncd#SDK: [SAI_UTILS.NOTICE] ./src/mlnx_sai_utils.c[1911]- set_dispatch_attrib_handler: Set EGRESS_DISABLE, key:LAG_MEMBER [OID:0x1000F0001001B] [log_port:0x1000F, lag_log_id:0x1], val:true
Sep 21 12:44:49.482347 sonic NOTICE swss#orchagent: :- setDistributionOnLagMember: Disable distribution on LAG member Ethernet184
Sep 21 12:44:49.482347 sonic NOTICE syncd#SDK: [SAI_UTILS.NOTICE] ./src/mlnx_sai_utils.c[1911]- set_dispatch_attrib_handler: Set INGRESS_DISABLE, key:LAG_MEMBER [OID:0x1000F0001001B] [log_port:0x1000F, lag_log_id:0x1], val:true
Sep 21 12:44:49.482347 sonic NOTICE swss#orchagent: :- setCollectionOnLagMember: Disable collection on LAG member Ethernet184
Sep 21 12:44:49.489985 sonic NOTICE swss#orchagent: :- updatePortOperStatus: Port PortChannel184 oper state set from up to down
Sep 21 12:44:49.489985 sonic NOTICE swss#orchagent: :- flushFdbEntries: flush key: SAI_OBJECT_TYPE_FDB_FLUSH:oid:0x21000000000000, fields: 2
Sep 21 12:44:49.489985 sonic NOTICE swss#orchagent: :- recordFlushFdbEntries: flush key: SAI_OBJECT_TYPE_FDB_FLUSH:oid:0x21000000000000, fields: 2
Sep 21 12:44:49.508641 sonic NOTICE syncd#SDK: [SAI_FDB.NOTICE] ./src/mlnx_sai_fdb.c[1425]- mlnx_flush_fdb_entries: Create FDB_FLUSH: #0 BRIDGE_PORT_ID=BRIDGE_PORT [OID:0x10000003A] [bridge_ports_db[1]] #1 ENTRY_TYPE=DYNAMIC
Sep 21 12:44:49.514402 sonic NOTICE syncd#SDK: :- processFdbFlush: fdb flush succeeded, updating redis database
Sep 21 12:44:49.514402 sonic NOTICE syncd#SDK: :- processFlushEvent: received a flush port fdb event, portVid = oid:0x3a0000000009b8, bvId = oid:0x0
Sep 21 12:44:49.514402 sonic NOTICE syncd#SDK: :- processFlushEvent: pattern ASIC_STATE:SAI_OBJECT_TYPE_FDB_ENTRY:*, portStr oid:0x3a0000000009b8
Sep 21 12:44:49.514402 sonic NOTICE swss#orchagent: :- meta_sai_on_fdb_flush_event_consolidated: processing consolidated fdb flush event of type: SAI_FDB_ENTRY_TYPE_DYNAMIC
Sep 21 12:44:49.514402 sonic NOTICE swss#orchagent: :- meta_sai_on_fdb_flush_event_consolidated: fdb flush took 0.000468 sec
Sep 21 12:44:49.514402 sonic NOTICE syncd#SDK: :- handle_fdb_event: got fdb flush event: [{"fdb_entry":"{\"bvid\":\"oid:0x0\",\"mac\":\"00:00:00:00:00:00\",\"switch_id\":\"oid:0x100000021\"}","fdb_event":"SAI_FDB_EVENT_FLUSHED","list":[{"id":"SAI_FDB_ENTRY_ATTR_BRIDGE_PORT_ID","value":"oid:0x10000003a"},{"id":"SAI_FDB_ENTRY_ATTR_TYPE","value":"SAI_FDB_ENTRY_TYPE_DYNAMIC"},{"id":"SAI_FDB_ENTRY_ATTR_PACKET_ACTION","value":"SAI_PACKET_ACTION_FORWARD"}]}]
Sep 21 12:44:49.514402 sonic NOTICE syncd#SDK: :- processFlushEvent: received a flush port fdb event, portVid = oid:0x3a0000000009b8, bvId = oid:0x0
Sep 21 12:44:49.514402 sonic NOTICE syncd#SDK: :- processFlushEvent: pattern ASIC_STATE:SAI_OBJECT_TYPE_FDB_ENTRY:*, portStr oid:0x3a0000000009b8
Sep 21 12:44:49.599313 sonic NOTICE syncd#SDK: [SAI_UTILS.NOTICE] ./src/mlnx_sai_utils.c[1911]- set_dispatch_attrib_handler: Set PACKET_ACTION, key:ROUTE_ENTRY :: ::, val:DROP
Sep 21 12:44:49.599313 sonic NOTICE syncd#SDK: [SAI_UTILS.NOTICE] ./src/mlnx_sai_utils.c[1911]- set_dispatch_attrib_handler: Set PACKET_ACTION, key:ROUTE_ENTRY 0.0.0.0 0.0.0.0, val:DROP
Sep 21 12:44:49.599313 sonic NOTICE syncd#SDK: [SAI_UTILS.NOTICE] ./src/mlnx_sai_utils.c[2319]- mlnx_bulk_statuses_print: [BULK_SET] 4 Routes: 4 success, 0 not executed, 0 failed
Sep 21 12:44:49.608331 sonic NOTICE swss#orchagent: :- meta_sai_on_fdb_flush_event_consolidated: processing consolidated fdb flush event of type: SAI_FDB_ENTRY_TYPE_DYNAMIC
Sep 21 12:44:49.608331 sonic NOTICE swss#orchagent: :- meta_sai_on_fdb_flush_event_consolidated: fdb flush took 0.000339 sec
Sep 21 12:44:49.636590 sonic NOTICE syncd#SDK: [SAI_UTILS.NOTICE] ./src/mlnx_sai_utils.c[1911]- set_dispatch_attrib_handler: Set TYPE, key:FDB_ENTRY [64:9d:99:17:cb:2c] [BV_ID:0x6400000026], val:STATIC
Sep 21 12:44:49.637124 sonic ERR syncd#SDK: [SAI_FDB.ERR] ./src/mlnx_sai_fdb.c[446]- mlnx_get_mac: Failed to get 0 fdb entries Entry Not Found.
Sep 21 12:44:49.637483 sonic ERR syncd#SDK: [SAI_UTILS.ERR] ./src/mlnx_sai_utils.c[1914]- set_dispatch_attrib_handler: Failed Set TYPE, key:FDB_ENTRY [64:9d:99:17:cb:2c] [BV_ID:0x6400000026], val:STATIC
Sep 21 12:44:49.637787 sonic ERR syncd#SDK: [SAI_UTILS.ERR] ./src/mlnx_sai_utils.c[2134]- sai_set_attribute: Failed to set the attribute.
Sep 21 12:44:49.638516 sonic ERR syncd#SDK: :- sendApiResponse: api SAI_COMMON_API_SET failed in syncd mode: SAI_STATUS_ITEM_NOT_FOUND
Sep 21 12:44:49.638516 sonic ERR syncd#SDK: :- processQuadEvent: attr: SAI_FDB_ENTRY_ATTR_TYPE: SAI_FDB_ENTRY_TYPE_STATIC
Sep 21 12:44:49.639377 sonic ERR swss#orchagent: :- set: set status: SAI_STATUS_ITEM_NOT_FOUND
Sep 21 12:44:49.640152 sonic ERR swss#orchagent: :- addFdbEntry: macUpdate-Failed for attr.id=0x0 for FDB 64:9d:99:17:cb:2c in Vlan100 on PortChannel2001, rv:-7
Sep 21 12:44:49.640152 sonic ERR swss#orchagent: :- handleSaiSetStatus: Encountered failure in set operation, exiting orchagent, SAI API: SAI_API_FDB, status: SAI_STATUS_ITEM_NOT_FOUND
Sep 21 12:44:49.640152 sonic NOTICE swss#orchagent: :- notifySyncd: sending syncd: SYNCD_INVOKE_DUMP
Sep 21 12:44:49.640976 sonic NOTICE syncd#SDK: :- processNotifySyncd: Invoking SAI failure dump
Sep 21 12:44:49.678566 sonic INFO syncd#SDK: [LOG.INFO] Initializing SX log with user callback function.
Sep 21 12:44:49.690028 sonic NOTICE syncd#SDK: [DBG.NOTICE] Started DEBUG-DUMP
Sep 21 12:44:49.690996 sonic NOTICE syncd#SDK: [EMAD.NOTICE] setting emad-timeout to 1000000
Sep 21 12:44:50.050560 sonic NOTICE syncd#SDK: :- threadFunction: time span 409 ms for 'notify:SYNCD_INVOKE_DUMP'
Sep 21 12:44:51.050690 sonic NOTICE syncd#SDK: :- threadFunction: time span 1409 ms for 'notify:SYNCD_INVOKE_DUMP'
Sep 21 12:44:51.696899 sonic INFO systemd[1]: run-docker-runtime\x2drunc-moby-b08e3c24fd0869e6085e9476afff40e4ae88f12512be34edacf1be374a081168-runc.NTc3tx.mount: Succeeded.
Sep 21 12:44:52.050877 sonic NOTICE syncd#SDK: :- threadFunction: time span 2409 ms for 'notify:SYNCD_INVOKE_DUMP'
Sep 21 12:44:53.051192 sonic NOTICE syncd#SDK: :- threadFunction: time span 3409 ms for 'notify:SYNCD_INVOKE_DUMP'
Sep 21 12:44:53.292297 sonic NOTICE syncd#SDK: [EMAD.NOTICE] setting emad-timeout to 20000000
Sep 21 12:44:53.292498 sonic NOTICE syncd#SDK: [DBG.NOTICE] Finished DEBUG-DUMP
Sep 21 12:44:54.051070 sonic NOTICE syncd#SDK: :- threadFunction: time span 4410 ms for 'notify:SYNCD_INVOKE_DUMP'
Sep 21 12:44:54.939369 sonic NOTICE syncd#SDK: [COMMAND_IFC.NOTICE] COMMAND IFC:   COMMAND IFC INIT DONE
Sep 21 12:44:54.951600 sonic NOTICE syncd#SDK: [ACCESS_REG_INIT.NOTICE] ACCESS REG:   ACCESS REG INIT DONE
Sep 21 12:44:55.027014 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] Generating 3 CR-Space dumps
Sep 21 12:44:55.027444 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] FW dump using temporary file (/var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sdkdump_ext_meta_001-21_09_2023-04_44_55-26845iicobztbn.tmp).
Sep 21 12:44:55.027768 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] FW dump using temporary file (/var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sdkdump_ext_cr_001-21_09_2023-04_44_55-26845.udmprvqwkoqsm.tmp).
Sep 21 12:44:55.028048 sonic NOTICE syncd#SDK: [SXD_FW_DBG.NOTICE] sxd_fw_dbg_extract FW instruction structure for type:[8] not yet initialized, trying to initialize it now
Sep 21 12:44:55.028406 sonic NOTICE syncd#SDK: [SXD_FW_DBG.NOTICE] file:[Spectrum.csv] lines:[22359]
Sep 21 12:44:55.031503 sonic NOTICE syncd#SDK: [SXD_FW_DBG.NOTICE] file:[Spectrum.csv] parsing done
Sep 21 12:44:55.051145 sonic NOTICE syncd#SDK: :- threadFunction: time span 5410 ms for 'notify:SYNCD_INVOKE_DUMP'
Sep 21 12:44:55.368815 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] SDK extra dump meta file saved to:[/var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sdkdump_ext_meta_001-21_09_2023-04_44_55-26845]
Sep 21 12:44:55.369248 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] SDK extra dump file CR saved to:[/var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sdkdump_ext_cr_001-21_09_2023-04_44_55-26845.udmp]
Sep 21 12:44:55.369566 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] FW dump using temporary file (/var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sdkdump_ext_meta_001-21_09_2023-04_44_55-368629wcpsgesme.tmp).
Sep 21 12:44:55.369830 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] FW dump using temporary file (/var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sdkdump_ext_cr_001-21_09_2023-04_44_55-368629.udmprprnbarqb.tmp).
Sep 21 12:44:55.370084 sonic NOTICE syncd#SDK: [SXD_FW_DBG.NOTICE] sxd_fw_dbg_extract FW instruction structure for type:[8] not yet initialized, trying to initialize it now
Sep 21 12:44:55.370329 sonic NOTICE syncd#SDK: [SXD_FW_DBG.NOTICE] file:[Spectrum.csv] lines:[22359]
Sep 21 12:44:55.373346 sonic NOTICE syncd#SDK: [SXD_FW_DBG.NOTICE] file:[Spectrum.csv] parsing done
Sep 21 12:44:55.716589 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] SDK extra dump meta file saved to:[/var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sdkdump_ext_meta_001-21_09_2023-04_44_55-368629]
Sep 21 12:44:55.717037 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] SDK extra dump file CR saved to:[/var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sdkdump_ext_cr_001-21_09_2023-04_44_55-368629.udmp]
Sep 21 12:44:55.717376 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] FW dump using temporary file (/var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sdkdump_ext_meta_001-21_09_2023-04_44_55-716450cunjkhyeo.tmp).
Sep 21 12:44:55.717687 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] FW dump using temporary file (/var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sdkdump_ext_cr_001-21_09_2023-04_44_55-716450.udmpajsfiuuba.tmp).
Sep 21 12:44:55.717956 sonic NOTICE syncd#SDK: [SXD_FW_DBG.NOTICE] sxd_fw_dbg_extract FW instruction structure for type:[8] not yet initialized, trying to initialize it now
Sep 21 12:44:55.718200 sonic NOTICE syncd#SDK: [SXD_FW_DBG.NOTICE] file:[Spectrum.csv] lines:[22359]
Sep 21 12:44:55.721153 sonic NOTICE syncd#SDK: [SXD_FW_DBG.NOTICE] file:[Spectrum.csv] parsing done
Sep 21 12:44:56.057476 sonic NOTICE syncd#SDK: :- threadFunction: time span 6416 ms for 'notify:SYNCD_INVOKE_DUMP'
Sep 21 12:44:56.072584 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] SDK extra dump meta file saved to:[/var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sdkdump_ext_meta_001-21_09_2023-04_44_55-716450]
Sep 21 12:44:56.073155 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] SDK extra dump file CR saved to:[/var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sdkdump_ext_cr_001-21_09_2023-04_44_55-716450.udmp]
Sep 21 12:44:56.073761 sonic NOTICE syncd#SDK: [SX_API_DBG_AMBER.NOTICE] AMBER Dump: Starting dump process to file /var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/amber_dump_001-21_09_2023-04_44_56.hex
Sep 21 12:44:56.074267 sonic NOTICE syncd#SDK: [EMAD.NOTICE] setting emad-timeout to 1000000
Sep 21 12:44:57.057652 sonic NOTICE syncd#SDK: :- threadFunction: time span 7416 ms for 'notify:SYNCD_INVOKE_DUMP'
Sep 21 12:44:57.245762 sonic NOTICE syncd#SDK: [EMAD.NOTICE] setting emad-timeout to 20000000
Sep 21 12:44:57.248532 sonic NOTICE syncd#SDK: [SAI_SWITCH.NOTICE] ./src/mlnx_sai_switch.c[5444]- mlnx_switch_dfw_thread_func: DFW thread got completed async dump.
Sep 21 12:44:57.249065 sonic NOTICE syncd#SDK: :- main: The SAI dump is generated to /var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sai_sdk_dump_09_21_2023_04_44_AM .
Sep 21 12:44:57.488669 sonic INFO syncd#supervisord 2023-09-21 04:44:57,487 INFO reaped unknown pid 608 (exit status 0)
Sep 21 12:44:58.057743 sonic NOTICE syncd#SDK: :- threadFunction: time span 8416 ms for 'notify:SYNCD_INVOKE_DUMP'
Sep 21 12:44:58.856789 sonic INFO systemd[1]: run-docker-runtime\x2drunc-moby-b08e3c24fd0869e6085e9476afff40e4ae88f12512be34edacf1be374a081168-runc.bqhVH7.mount: Succeeded.
Sep 21 12:44:59.057870 sonic NOTICE syncd#SDK: :- threadFunction: time span 9416 ms for 'notify:SYNCD_INVOKE_DUMP'
Sep 21 12:44:59.157233 sonic NOTICE swss#orchagent: :- sai_redis_notify_syncd: invoked DUMP succeeded
Sep 21 12:45:01.453593 sonic INFO swss#supervisord 2023-09-21 12:45:01,452 INFO exited: orchagent (terminated by SIGABRT (core dumped); not expected)
Sep 21 12:45:02.460844 sonic INFO swss#supervisor-proc-exit-listener: Process 'orchagent' exited unexpectedly. Terminating supervisor 'swss'
Sep 21 12:45:02.462097 sonic NOTICE swss#supervisor-proc-exit-listener: :- publish: EVENT_PUBLISHED: {"sonic-events-host:process-exited-unexpectedly":{"ctr_name":"swss","process_name":"orchagent","timestamp":"2023-09-21T12:45:02.461532Z"}}
Sep 21 12:45:02.465331 sonic INFO swss#supervisord 2023-09-21 12:45:02,464 WARN received SIGTERM indicating exit request
Sep 21 12:45:02.466432 sonic INFO swss#supervisord 2023-09-21 12:45:02,465 INFO waiting for supervisor-proc-exit-listener, rsyslogd, portsyncd, coppmgrd, arp_update, ndppd, neighsyncd, vlanmgrd, intfmgrd, portmgrd, buffermgrd, vrfmgrd, nbrmgrd, vxlanmgrd, fdbsyncd, tunnelmgrd, containercfgd to die
Sep 21 12:45:02.509755 sonic INFO swss#supervisord 2023-09-21 12:45:02,508 INFO stopped: containercfgd (exit status 143)
Sep 21 12:45:02.512769 sonic INFO swss#supervisord 2023-09-21 12:45:02,511 INFO stopped: tunnelmgrd (terminated by SIGTERM)
Sep 21 12:45:02.521225 sonic INFO swss#supervisord 2023-09-21 12:45:02,518 INFO stopped: fdbsyncd (terminated by SIGTERM)
Sep 21 12:45:02.528158 sonic INFO swss#supervisord 2023-09-21 12:45:02,526 INFO stopped: vxlanmgrd (terminated by SIGTERM)
Sep 21 12:45:02.543398 sonic INFO swss#supervisord 2023-09-21 12:45:02,538 INFO stopped: nbrmgrd (terminated by SIGTERM)
Sep 21 12:45:02.549870 sonic INFO swss#supervisord 2023-09-21 12:45:02,547 INFO stopped: vrfmgrd (terminated by SIGTERM)
Sep 21 12:45:03.555502 sonic INFO swss#supervisord 2023-09-21 12:45:03,554 INFO stopped: buffermgrd (terminated by SIGTERM)
Sep 21 12:45:03.558365 sonic INFO swss#supervisord 2023-09-21 12:45:03,557 INFO stopped: portmgrd (terminated by SIGTERM)
Sep 21 12:45:03.569065 sonic INFO swss#supervisord 2023-09-21 12:45:03,566 INFO stopped: intfmgrd (terminated by SIGTERM)
Sep 21 12:45:03.573656 sonic INFO swss#supervisord 2023-09-21 12:45:03,572 INFO stopped: vlanmgrd (terminated by SIGTERM)
Sep 21 12:45:04.579073 sonic INFO swss#supervisord 2023-09-21 12:45:04,575 INFO stopped: neighsyncd (terminated by SIGTERM)
Sep 21 12:45:04.579073 sonic INFO swss#supervisord: orchagent
Sep 21 12:45:04.579073 sonic INFO swss#supervisord: ndppd (error) Shutting down...
Sep 21 12:45:04.579073 sonic INFO swss#supervisord: ndppd (notice) Bye
Sep 21 12:45:04.579073 sonic INFO swss#supervisord 2023-09-21 12:45:04,577 INFO stopped: ndppd (exit status 0)
Sep 21 12:45:05.583063 sonic INFO swss#supervisord 2023-09-21 12:45:05,580 INFO stopped: arp_update (terminated by SIGTERM)
Sep 21 12:45:05.585256 sonic INFO swss#supervisord 2023-09-21 12:45:05,581 INFO waiting for supervisor-proc-exit-listener, rsyslogd, portsyncd, coppmgrd to die
Sep 21 12:45:05.586518 sonic INFO swss#supervisord 2023-09-21 12:45:05,585 INFO stopped: coppmgrd (terminated by SIGTERM)
Sep 21 12:45:06.198351 sonic INFO systemd[1]: run-docker-runtime\x2drunc-moby-b08e3c24fd0869e6085e9476afff40e4ae88f12512be34edacf1be374a081168-runc.4EMsr5.mount: Succeeded.
Sep 21 12:45:07.591907 sonic INFO swss#supervisord 2023-09-21 12:45:07,591 INFO stopped: portsyncd (terminated by SIGTERM)
Sep 21 12:45:08.700391 sonic INFO dockerd[589]: time="2023-09-21T12:45:08.699315085+08:00" level=info msg="ignoring event" container=fe2448156c117fd686f851337f1fd88e58e19fa0f97a22fd20bec3823cd7b4f6 module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
Sep 21 12:45:08.701799 sonic INFO containerd[391]: time="2023-09-21T12:45:08.701079351+08:00" level=info msg="shim disconnected" id=fe2448156c117fd686f851337f1fd88e58e19fa0f97a22fd20bec3823cd7b4f6
Sep 21 12:45:08.702872 sonic INFO containerd[391]: time="2023-09-21T12:45:08.702746606+08:00" level=warning msg="cleaning up after shim disconnected" id=fe2448156c117fd686f851337f1fd88e58e19fa0f97a22fd20bec3823cd7b4f6 namespace=moby
Sep 21 12:45:08.704096 sonic INFO containerd[391]: time="2023-09-21T12:45:08.703963317+08:00" level=info msg="cleaning up dead shim"
Sep 21 12:45:08.723691 sonic INFO containerd[391]: time="2023-09-21T12:45:08.723543714+08:00" level=warning msg="cleanup warnings time=\"2023-09-21T12:45:08+08:00\" level=info msg=\"starting signal loop\" namespace=moby pid=1180676 runtime=io.containerd.runc.v2\n"
Sep 21 12:45:08.778711 sonic INFO systemd[1]: var-lib-docker-overlay2-ac413ee3a30b27f1629731ffae06e1abc8e670180db7345cdf0d02762951ee31-merged.mount: Succeeded.
Sep 21 12:45:09.894299 sonic NOTICE root: Stopping swss service...
Sep 21 12:45:09.906223 sonic NOTICE root: Locking /tmp/swss-syncd-lock from swss service
Sep 21 12:45:09.921137 sonic NOTICE root: Locked /tmp/swss-syncd-lock (10) from swss service
Sep 21 12:45:09.969771 sonic NOTICE root: Warm boot flag: swss false.
Sep 21 12:45:09.999423 sonic NOTICE root: Fast boot flag: swss false.
Sep 21 12:45:10.764508 sonic DEBUG container: container_stop: BEGIN
Sep 21 12:45:10.767557 sonic DEBUG container: read_data: config:True feature:swss fields:[('set_owner', 'local'), ('no_fallback_to_local', False), ('state', 'disabled')] val:['local', False, 'enabled']
Sep 21 12:45:10.769056 sonic DEBUG container: read_data: config:False feature:swss fields:[('current_owner', 'none'), ('remote_state', 'none'), ('container_id', '')] val:['none', 'none', '']
Sep 21 12:45:10.770686 sonic DEBUG container: container_stop: swss: set_owner:local current_owner:none remote_state:none docker_id:swss
Sep 21 12:45:10.796449 sonic INFO container: docker cmd: stop for swss
Sep 21 12:45:10.797910 sonic DEBUG container: container_stop: END
Sep 21 12:45:10.904813 sonic NOTICE root: Stopped swss service...
Sep 21 12:45:10.938173 sonic INFO swss.sh[1180903]: 1
Sep 21 12:45:10.944386 sonic NOTICE root: Cleared PortInitDone from APPL_DB...
Sep 21 12:45:10.959347 sonic NOTICE root: Clearing FAST_RESTART_ENABLE_TABLE flag...
Sep 21 12:45:10.998142 sonic INFO swss.sh[1180911]: 0
Sep 21 12:45:11.005403 sonic NOTICE root: Unlocking /tmp/swss-syncd-lock (10) from swss service
Sep 21 12:45:11.036538 sonic INFO systemd[1]: Stopping TEAMD container...
Sep 21 12:45:11.046041 sonic NOTICE admin: Stopping teamd service...
Sep 21 12:45:11.116432 sonic NOTICE admin: Warm boot flag: teamd false.
Sep 21 12:45:11.130485 sonic NOTICE admin: Fast boot flag: teamd false.
Sep 21 12:45:12.036794 sonic DEBUG container: container_stop: BEGIN
Sep 21 12:45:12.039622 sonic DEBUG container: read_data: config:True feature:teamd fields:[('set_owner', 'local'), ('no_fallback_to_local', False), ('state', 'disabled')] val:['local', False, 'enabled']
Sep 21 12:45:12.040500 sonic DEBUG container: read_data: config:False feature:teamd fields:[('current_owner', 'none'), ('remote_state', 'none'), ('container_id', '')] val:['none', 'none', '']
Sep 21 12:45:12.042923 sonic DEBUG container: container_stop: teamd: set_owner:local current_owner:none remote_state:none docker_id:teamd
Sep 21 12:45:12.900810 sonic INFO teamd#supervisord 2023-09-21 12:45:12,896 WARN received SIGTERM indicating exit request
Sep 21 12:45:12.902232 sonic INFO teamd#supervisord 2023-09-21 12:45:12,901 INFO waiting for supervisor-proc-exit-listener, rsyslogd, teammgrd, teamsyncd, tlm_teamd, containercfgd to die
Sep 21 12:45:13.929645 sonic INFO teamd#supervisord 2023-09-21 12:45:13,928 INFO stopped: containercfgd (exit status 143)
Sep 21 12:45:14.931958 sonic NOTICE teamd#tlm_teamd: :- main: Exiting
Sep 21 12:45:14.933448 sonic NOTICE teamd#tlm_teamd: :- ~TeamdCtlMgr: Exiting. Disconnecting from teamd. LAG 'PortChannel2001'
Sep 21 12:45:14.933448 sonic NOTICE teamd#tlm_teamd: :- ~TeamdCtlMgr: Exiting. Disconnecting from teamd. LAG 'PortChannel184'
Sep 21 12:45:14.933448 sonic NOTICE teamd#tlm_teamd: :- ~TeamdCtlMgr: Exiting. Disconnecting from teamd. LAG 'PortChannel176'
Sep 21 12:45:15.409088 sonic INFO teamd#supervisord 2023-09-21 12:45:15,408 INFO stopped: tlm_teamd (exit status 0)
Sep 21 12:45:16.411960 sonic INFO teamd#supervisord 2023-09-21 12:45:16,409 INFO waiting for supervisor-proc-exit-listener, rsyslogd, teammgrd, teamsyncd to die
Sep 21 12:45:16.411960 sonic NOTICE teamd#teamsyncd: :- cleanTeamSync: Cleaning up LAG teamd resources ...
Sep 21 12:45:16.412416 sonic NOTICE teamd#teamsyncd: :- main: Received SIGTERM Exiting
Sep 21 12:45:16.972034 sonic INFO teamd#supervisord 2023-09-21 12:45:16,971 INFO stopped: teamsyncd (exit status 0)
Sep 21 12:45:17.973866 sonic NOTICE teamd#teammgrd: :- cleanTeamProcesses: Cleaning up LAGs during shutdown...
Sep 21 12:45:17.979810 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_newlink.NOTICE] Update local port PortChannel176 state down
Sep 21 12:45:17.980172 sonic NOTICE iccpd#mclagsyncd: :- mclagsyncdSetTrafficDisable: Set traffic disable for PortChannel176
Sep 21 12:45:17.980363 sonic INFO kernel: [94386.842029] Bridge: port 2(PortChannel176) entered disabled state
Sep 21 12:45:17.984475 sonic INFO kernel: [94386.843810] device Ethernet176 left promiscuous mode
Sep 21 12:45:17.984781 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_newlink.NOTICE] Update local port Ethernet176 state down
Sep 21 12:45:17.985264 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_deladdr.NOTICE] l3_proto 0, ifname Ethernet176 index 1687 is_vrf 0 address fe80::526b:4bff:fe9b:82c0
Sep 21 12:45:17.985724 sonic NOTICE iccpd#mclagsyncd: :- setPortIsolate: set port isolate, src port: PortChannel2001, dst port: PortChannel184,Ethernet184,PortChannel176
Sep 21 12:45:17.988320 sonic INFO kernel: [94386.849349] PortChannel176: Port device Ethernet176 removed
Sep 21 12:45:17.991548 sonic NOTICE teamd#teammgrd: :- cleanTeamProcesses: Sent SIGTERM to port channel PortChannel176 pid 28
Sep 21 12:45:17.994364 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_deladdr.NOTICE] l3_proto 0, ifname PortChannel176 index 1592 is_vrf 0 address fe80::63f:72ff:fe2f:3800
Sep 21 12:45:17.996502 sonic INFO kernel: [94386.857095] Bridge: port 2(PortChannel176) entered disabled state
Sep 21 12:45:17.997733 sonic WARNING iccpd#iccpd: [local_if_destroy.WARN] Destroy interface PortChannel176, 1592
Sep 21 12:45:17.998093 sonic NOTICE iccpd#iccpd: [local_if_del_all_vlan.NOTICE] Remove all VLANs from PortChannel176
Sep 21 12:45:17.998300 sonic NOTICE iccpd#mclagsyncd: :- mclagsyncdSetTrafficDisable: Set traffic enable for PortChannel176
Sep 21 12:45:18.000366 sonic INFO kernel: [94386.860007] device PortChannel176 left promiscuous mode
Sep 21 12:45:18.000395 sonic INFO kernel: [94386.860034] Bridge: port 2(PortChannel176) entered disabled state
Sep 21 12:45:18.004471 sonic NOTICE teamd#teammgrd: :- cleanTeamProcesses: Sent SIGTERM to port channel PortChannel184 pid 36
Sep 21 12:45:18.009245 sonic NOTICE teamd#teammgrd: :- cleanTeamProcesses: Sent SIGTERM to port channel PortChannel2001 pid 44
Sep 21 12:45:18.009562 sonic NOTICE teamd#teammgrd: :- cleanTeamProcesses: Waiting for port channel PortChannel2001 pid 44 to stop...
Sep 21 12:45:18.030587 sonic INFO kernel: [94386.888742] device Ethernet184 left promiscuous mode
Sep 21 12:45:18.030614 sonic INFO kernel: [94386.893048] PortChannel184: Port device Ethernet184 removed
Sep 21 12:45:18.030645 sonic NOTICE iccpd#mclagsyncd: :- setPortIsolate: set port isolate, src port: PortChannel2001, dst port: PortChannel184
Sep 21 12:45:18.043298 sonic INFO kernel: [94386.898234] device Ethernet196 left promiscuous mode
Sep 21 12:45:18.043323 sonic INFO kernel: [94386.901426] PortChannel2001: Port device Ethernet196 removed
Sep 21 12:45:18.043326 sonic INFO kernel: [94386.902726] Bridge: port 4(PortChannel2001) entered disabled state
Sep 21 12:45:18.043327 sonic INFO kernel: [94386.904787] device Ethernet192 left promiscuous mode
Sep 21 12:45:18.043375 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_newlink.NOTICE] Update local port Ethernet196 state down
Sep 21 12:45:18.043375 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_deladdr.NOTICE] l3_proto 0, ifname Ethernet196 index 1692 is_vrf 0 address fe80::526b:4bff:fe9b:82c0
Sep 21 12:45:18.043375 sonic NOTICE iccpd#mclagsyncd: :- setPortMacLearnMode: set port mac learn mode, port: Ethernet196, learn-mode: hardware
Sep 21 12:45:18.043375 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_newlink.NOTICE] Update local port PortChannel2001 state down
Sep 21 12:45:18.043375 sonic NOTICE iccpd#mclagsyncd: :- setFdbEntry: del fdb entry from ASIC_DB:key =Vlan10:04:3f:72:2f:38:00
Sep 21 12:45:18.043375 sonic NOTICE iccpd#mclagsyncd: :- setFdbEntry: del fdb entry from ASIC_DB:key =Vlan100:04:3f:72:2f:38:00
Sep 21 12:45:18.043375 sonic NOTICE iccpd#mclagsyncd: :- setFdbEntry: del fdb entry from ASIC_DB:key =Vlan100:64:9d:99:17:cb:2c
Sep 21 12:45:18.048576 sonic INFO kernel: [94386.910831] PortChannel2001: Port device Ethernet192 removed
Sep 21 12:45:18.048626 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_newlink.NOTICE] Update local port Ethernet192 state down
Sep 21 12:45:18.048626 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_deladdr.NOTICE] l3_proto 0, ifname Ethernet192 index 1691 is_vrf 0 address fe80::526b:4bff:fe9b:82c0
Sep 21 12:45:18.048626 sonic NOTICE iccpd#mclagsyncd: :- setPortMacLearnMode: set port mac learn mode, port: Ethernet192, learn-mode: hardware
Sep 21 12:45:18.087773 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fe80::/64 :: eth0
Sep 21 12:45:18.087773 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: 0.0.0.0/0 192.168.0.1 eth0
Sep 21 12:45:18.087773 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: ::/0 fe80::21b:21ff:febe:2f0 eth0
Sep 21 12:45:18.087773 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fd00::/80 :: docker0
Sep 21 12:45:18.087773 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: 0.0.0.0/0 192.168.0.1 eth0
Sep 21 12:45:18.087773 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: ::/0 fe80::21b:21ff:febe:2f0 eth0
Sep 21 12:45:18.087773 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fd00::/80 :: docker0
Sep 21 12:45:18.087773 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fe80::/64 :: eth0
Sep 21 12:45:18.087773 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: 0.0.0.0/0 192.168.0.1 eth0
Sep 21 12:45:18.087773 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: ::/0 fe80::21b:21ff:febe:2f0 eth0
Sep 21 12:45:18.087773 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fd00::/80 :: docker0
Sep 21 12:45:18.094756 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_deladdr.NOTICE] l3_proto 0, ifname PortChannel184 index 1601 is_vrf 0 address fe80::63f:72ff:fe2f:3800
Sep 21 12:45:18.103547 sonic INFO kernel: [94386.957158] Bridge: port 3(PortChannel184) entered disabled state
Sep 21 12:45:18.103576 sonic INFO kernel: [94386.958188] device PortChannel184 left promiscuous mode
Sep 21 12:45:18.103580 sonic INFO kernel: [94386.958210] Bridge: port 3(PortChannel184) entered disabled state
Sep 21 12:45:18.103623 sonic WARNING iccpd#iccpd: [local_if_destroy.WARN] Destroy interface PortChannel184, 1601
Sep 21 12:45:18.103623 sonic NOTICE iccpd#iccpd: [local_if_del_all_vlan.NOTICE] Remove all VLANs from PortChannel184
Sep 21 12:45:18.103623 sonic NOTICE iccpd#mclagsyncd: :- mclagsyncdSetTrafficDisable: Set traffic enable for PortChannel184
Sep 21 12:45:18.126455 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_deladdr.NOTICE] l3_proto 0, ifname PortChannel2001 index 1608 is_vrf 0 address fe80::526b:4bff:fe9b:82c0
Sep 21 12:45:18.128311 sonic INFO kernel: [94386.989136] Bridge: port 4(PortChannel2001) entered disabled state
Sep 21 12:45:18.128338 sonic INFO kernel: [94386.989724] device PortChannel2001 left promiscuous mode
Sep 21 12:45:18.128340 sonic INFO kernel: [94386.989745] Bridge: port 4(PortChannel2001) entered disabled state
Sep 21 12:45:18.128566 sonic WARNING iccpd#iccpd: [local_if_destroy.WARN] Destroy interface PortChannel2001, 1608
Sep 21 12:45:18.128651 sonic NOTICE iccpd#iccpd: [ICCP_FSM.NOTICE] scheduler session disconnect handler
Sep 21 12:45:18.128853 sonic NOTICE iccpd#iccpd: [ICCP_FSM.NOTICE] CSM socket 17 close, location 1
Sep 21 12:45:18.128889 sonic NOTICE iccpd#iccpd: [ICCP_FSM.NOTICE] ICCP session down: warm reboot no, role standby, sync_state MLACP_STATE_EXCHANGE
Sep 21 12:45:18.129269 sonic NOTICE iccpd#iccpd: [update_vlan_if_mac_on_iccp_up.NOTICE]  lif name PortChannel2001, up 0
Sep 21 12:45:18.129353 sonic NOTICE iccpd#iccpd: [recover_vlan_if_mac_on_standby.NOTICE]  remote system_id not initialised.
Sep 21 12:45:18.129565 sonic NOTICE iccpd#iccpd: [recover_vlan_if_mac_on_standby.NOTICE]  remote system_id not initialised.
Sep 21 12:45:18.129565 sonic NOTICE iccpd#iccpd: [ICCP_FDB.NOTICE] mlacp_mac_msg_queue_reinit clear mac_msg_list pointers in existing MAC entries
Sep 21 12:45:18.129749 sonic NOTICE iccpd#iccpd: [local_if_del_all_vlan.NOTICE] Remove all VLANs from PortChannel2001
Sep 21 12:45:18.130065 sonic NOTICE iccpd#mclagsyncd: :- setFdbEntry: del fdb entry from ASIC_DB:key =Vlan10:04:3f:72:2f:38:00
Sep 21 12:45:18.130324 sonic NOTICE iccpd#mclagsyncd: :- setFdbEntry: del fdb entry from ASIC_DB:key =Vlan100:04:3f:72:2f:38:00
Sep 21 12:45:18.130548 sonic NOTICE iccpd#mclagsyncd: :- setFdbEntry: del fdb entry from ASIC_DB:key =Vlan100:64:9d:99:17:cb:2c
Sep 21 12:45:18.130799 sonic NOTICE iccpd#mclagsyncd: :- mclagsyncdSetIccpState: Set mlag 1 ICCP state to down
Sep 21 12:45:18.131063 sonic NOTICE iccpd#mclagsyncd: :- mclagsyncdSetSystemId: Set mlag 1 system mac to 50:6b:4b:9b:82:c0
Sep 21 12:45:18.131277 sonic NOTICE iccpd#mclagsyncd: :- mclagsyncdDelRemoteIfInfo: Delete mlag 1, remote interface PortChannel176
Sep 21 12:45:18.131492 sonic NOTICE iccpd#mclagsyncd: :- mclagsyncdDelRemoteIfInfo: Delete mlag 1, remote interface PortChannel184
Sep 21 12:45:18.163669 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: 0.0.0.0/0 192.168.0.1 eth0
Sep 21 12:45:18.163669 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: ::/0 fe80::21b:21ff:febe:2f0 eth0
Sep 21 12:45:18.163669 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fd00::/80 :: docker0
Sep 21 12:45:18.167363 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: 0.0.0.0/0 192.168.0.1 eth0
Sep 21 12:45:18.177880 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: ::/0 fe80::21b:21ff:febe:2f0 eth0
Sep 21 12:45:18.177880 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fd00::/80 :: docker0
Sep 21 12:45:18.975330 sonic INFO teamd#supervisord 2023-09-21 12:45:18,973 INFO reaped unknown pid 28 (exit status 0)
Sep 21 12:45:18.975330 sonic INFO teamd#supervisord 2023-09-21 12:45:18,974 INFO reaped unknown pid 36 (exit status 0)
Sep 21 12:45:18.975330 sonic INFO teamd#supervisord 2023-09-21 12:45:18,974 INFO reaped unknown pid 44 (exit status 0)
Sep 21 12:45:18.986955 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_newlink.NOTICE] Update local port Vlan10 state down
Sep 21 12:45:18.988649 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_newlink.NOTICE] Update local port Vlan100 state down
Sep 21 12:45:18.997110 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fe80::/64 :: eth0
Sep 21 12:45:18.997179 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: 0.0.0.0/0 192.168.0.1 eth0
Sep 21 12:45:18.997397 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: ::/0 fe80::21b:21ff:febe:2f0 eth0
Sep 21 12:45:18.997857 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fd00::/80 :: docker0
Sep 21 12:45:19.013241 sonic NOTICE teamd#teammgrd: :- cleanTeamProcesses: Waiting for port channel PortChannel184 pid 36 to stop...
Sep 21 12:45:19.020359 sonic NOTICE teamd#teammgrd: :- cleanTeamProcesses: Waiting for port channel PortChannel176 pid 28 to stop...
Sep 21 12:45:19.020359 sonic NOTICE teamd#teammgrd: :- cleanTeamProcesses: LAGs cleanup is done
Sep 21 12:45:19.020359 sonic NOTICE teamd#teammgrd: :- main: Exiting
Sep 21 12:45:19.221554 sonic INFO teamd#supervisord 2023-09-21 12:45:19,212 INFO stopped: teammgrd (exit status 0)
Sep 21 12:45:20.355124 sonic INFO containerd[391]: time="2023-09-21T12:45:20.353731751+08:00" level=info msg="shim disconnected" id=27273f07b770a3f406ba4c442239b982fff17cd054d2d9aee8b04310c2249fa7
Sep 21 12:45:20.355256 sonic INFO containerd[391]: time="2023-09-21T12:45:20.353822579+08:00" level=warning msg="cleaning up after shim disconnected" id=27273f07b770a3f406ba4c442239b982fff17cd054d2d9aee8b04310c2249fa7 namespace=moby
Sep 21 12:45:20.355337 sonic INFO containerd[391]: time="2023-09-21T12:45:20.353849604+08:00" level=info msg="cleaning up dead shim"
Sep 21 12:45:20.356658 sonic INFO dockerd[589]: time="2023-09-21T12:45:20.355608603+08:00" level=info msg="ignoring event" container=27273f07b770a3f406ba4c442239b982fff17cd054d2d9aee8b04310c2249fa7 module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
Sep 21 12:45:20.395449 sonic INFO containerd[391]: time="2023-09-21T12:45:20.395298825+08:00" level=warning msg="cleanup warnings time=\"2023-09-21T12:45:20+08:00\" level=info msg=\"starting signal loop\" namespace=moby pid=1181807 runtime=io.containerd.runc.v2\n"
Sep 21 12:45:20.453520 sonic INFO systemd[1]: var-lib-docker-overlay2-1dc204245c2f4eb4429a5504ff2ef3b996e1596a2e1e3c0c302ea37f9689c9de-merged.mount: Succeeded.
Sep 21 12:45:20.515506 sonic INFO container: docker cmd: wait for teamd
Sep 21 12:45:20.528427 sonic INFO container: docker cmd: stop for teamd
Sep 21 12:45:20.532899 sonic DEBUG container: container_stop: END
Sep 21 12:45:20.693741 sonic NOTICE admin: Stopped teamd service...
Sep 21 12:45:20.706308 sonic INFO systemd[1]: teamd.service: Succeeded.
Sep 21 12:45:20.706454 sonic INFO systemd[1]: Stopped TEAMD container.
Sep 21 12:45:20.711028 sonic NOTICE rsyslog_plugin: :- publish: EVENT_PUBLISHED: {"sonic-events-host:event-stopped-ctr":{"ctr_name":"TEAMD","timestamp":"2023-09-21T12:45:20.706783Z"}}
Sep 21 12:45:20.731952 sonic INFO systemd[1]: Stopping Router advertiser container...
Sep 21 12:45:20.752767 sonic NOTICE admin: Stopping radv service...
Sep 21 12:45:20.758480 sonic NOTICE healthd: System is not ready - one or more services are not up
Sep 21 12:45:20.858399 sonic NOTICE admin: DEVICE_SUBTYPE: , CONFIG_KNOB:
Sep 21 12:45:20.870442 sonic NOTICE admin: Warm boot flag: radv false.
Sep 21 12:45:20.882539 sonic NOTICE admin: Fast boot flag: radv false.
Sep 21 12:45:21.373791 sonic INFO systemd[1]: run-docker-runtime\x2drunc-moby-b08e3c24fd0869e6085e9476afff40e4ae88f12512be34edacf1be374a081168-runc.YSFl4f.mount: Succeeded.
Sep 21 12:45:21.859681 sonic DEBUG container: container_stop: BEGIN
Sep 21 12:45:21.863155 sonic DEBUG container: read_data: config:True feature:radv fields:[('set_owner', 'local'), ('no_fallback_to_local', False), ('state', 'disabled')] val:['local', False, 'enabled']
Sep 21 12:45:21.865428 sonic DEBUG container: read_data: config:False feature:radv fields:[('current_owner', 'none'), ('remote_state', 'none'), ('container_id', '')] val:['none', 'none', '']
Sep 21 12:45:21.868155 sonic DEBUG container: container_stop: radv: set_owner:local current_owner:none remote_state:none docker_id:radv
Sep 21 12:45:22.265046 sonic INFO radv#supervisord 2023-09-21 12:45:22,262 WARN received SIGTERM indicating exit request
Sep 21 12:45:22.265046 sonic INFO radv#supervisord 2023-09-21 12:45:22,262 INFO waiting for supervisor-proc-exit-script, rsyslogd, containercfgd to die
Sep 21 12:45:23.290400 sonic INFO radv#supervisord 2023-09-21 12:45:23,289 INFO stopped: containercfgd (exit status 143)
Sep 21 12:45:24.385870 sonic INFO containerd[391]: time="2023-09-21T12:45:24.385146831+08:00" level=info msg="shim disconnected" id=da036c5ecf286d7bf932731bd657f618ec8fb6193939179ef7bf5ea90179babd
Sep 21 12:45:24.385993 sonic INFO containerd[391]: time="2023-09-21T12:45:24.385241765+08:00" level=warning msg="cleaning up after shim disconnected" id=da036c5ecf286d7bf932731bd657f618ec8fb6193939179ef7bf5ea90179babd namespace=moby
Sep 21 12:45:24.386096 sonic INFO containerd[391]: time="2023-09-21T12:45:24.385268266+08:00" level=info msg="cleaning up dead shim"
Sep 21 12:45:24.386770 sonic INFO dockerd[589]: time="2023-09-21T12:45:24.385724214+08:00" level=info msg="ignoring event" container=da036c5ecf286d7bf932731bd657f618ec8fb6193939179ef7bf5ea90179babd module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
Sep 21 12:45:24.404119 sonic INFO containerd[391]: time="2023-09-21T12:45:24.403953665+08:00" level=warning msg="cleanup warnings time=\"2023-09-21T12:45:24+08:00\" level=info msg=\"starting signal loop\" namespace=moby pid=1181995 runtime=io.containerd.runc.v2\n"
Sep 21 12:45:24.453500 sonic INFO systemd[1]: var-lib-docker-overlay2-d999e1bac7d4a8364665ceffcbf4da5b3161d5b25c43b2aee052f111bef78f78-merged.mount: Succeeded.
Sep 21 12:45:24.501561 sonic INFO container: docker cmd: wait for radv
Sep 21 12:45:24.506965 sonic INFO container: docker cmd: stop for radv
Sep 21 12:45:24.508845 sonic DEBUG container: container_stop: END
Sep 21 12:45:24.607124 sonic NOTICE admin: Stopped radv service...
Sep 21 12:45:24.638623 sonic INFO systemd[1]: radv.service: Succeeded.
Sep 21 12:45:24.638777 sonic INFO systemd[1]: Stopped Router advertiser container.
Sep 21 12:45:24.642218 sonic NOTICE rsyslog_plugin: :- publish: EVENT_PUBLISHED: {"sonic-events-host:event-stopped-ctr":{"ctr_name":"Router advertiser","timestamp":"2023-09-21T12:45:24.639696Z"}}
Sep 21 12:45:24.656412 sonic INFO systemd[1]: Stopping BGP container...
Sep 21 12:45:24.677137 sonic NOTICE admin: Stopping bgp service...
Sep 21 12:45:24.744531 sonic NOTICE admin: Warm boot flag: bgp false.
Sep 21 12:45:24.755566 sonic NOTICE admin: Fast boot flag: bgp false.
Sep 21 12:45:25.305180 sonic INFO dbus-daemon[368]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.24' (uid=0 pid=1182091 comm="systemd-analyze plot ")

I notice there are some issue related to crash like #2332. I think this behavior happen randomly regardless if MAC address is static or dynamic.

I also attach dump log file too.

sai_sdk_dump_09_21_2023_04_47_AM.tar.gz
@naaysayer
Copy link

I am trying mclag with 2 mellanox SN2410 switch. I build the sonic firmware using master branch of sonic-buildimage with INCLUDE_ICCPD = y.

Switch 1 mclag configuration:

# Enable iccpd feature
config feature state iccpd enabled

# Peer link: Port Channel
config portchannel add PortChannel2001
config portchannel member add PortChannel2001 Ethernet192
config portchannel member add PortChannel2001 Ethernet196
config switchport mode trunk PortChannel2001

# Peer Link: VLAN
config vlan add 10
config vlan member add 10 PortChannel2001

# MCLAG domain
config mclag add 1 192.168.10.1 192.168.10.2 PortChannel2001
config mclag unique-ip add Vlan10
config interface ip add Vlan10 192.168.10.1/24

config vlan add 100
config mclag unique-ip add Vlan100
config vlan member add 100 PortChannel2001
config interface ip add Vlan100 192.168.100.1/24

# Create mlag port channel interface
ID=184
config portchannel add PortChannel$ID
config portchannel member add PortChannel$ID Ethernet$ID
config switchport mode trunk PortChannel$ID
config mclag member add 1 PortChannel$ID
config vlan member add 100 PortChannel$ID

Switch 2 mclag configuration:

# Enable iccpd feature
config feature state iccpd enabled

# Peer link: Port Channel
config portchannel add PortChannel2001
config portchannel member add PortChannel2001 Ethernet192
config portchannel member add PortChannel2001 Ethernet196
config switchport mode trunk PortChannel2001

# Peer Link: VLAN
config vlan add 10
config vlan member add 10 PortChannel2001

# MCLAG domain
config mclag add 1 192.168.10.2 192.168.10.1 PortChannel2001
config mclag unique-ip add Vlan10
config interface ip add Vlan10 192.168.10.2/24

config vlan add 100
config mclag unique-ip add Vlan100
config vlan member add 100 PortChannel2001
config interface ip add Vlan100 192.168.100.2/24

# Create mlag port channel interface
ID=184
config portchannel add PortChannel$ID
config portchannel member add PortChannel$ID Ethernet$ID
config switchport mode trunk PortChannel$ID
config mclag member add 1 PortChannel$ID
config vlan member add 100 PortChannel$ID

Runtime information for switch 1:

$ show int portchannel
Flags: A - active, I - inactive, Up - up, Dw - Down, N/A - not available,
       S - selected, D - deselected, * - not synced
  No.  Team Dev         Protocol     Ports
-----  ---------------  -----------  -----------------------------
  184  PortChannel184   LACP(A)(Up)  Ethernet184(S)
 2001  PortChannel2001  LACP(A)(Up)  Ethernet192(S) Ethernet196(S)

$ mclagdctl dump state
The MCLAG's keepalive is: OK
MCLAG info sync is: completed
Domain id: 1
Local Ip: 192.168.10.1
Peer Ip: 192.168.10.2
Peer Link Interface: PortChannel2001
Keepalive time: 1
sesssion Timeout : 15
Peer Link Mac: 04:3f:72:2f:38:00
Role: Active
MCLAG Interface: PortChannel184
Loglevel: NOTICE

$ mclagdctl dump mac -i 1
TYPE: S-STATIC, D-DYNAMIC; AGE: L-Local age, P-Peer age
No.   TYPE MAC                 VID  DEV                 ORIGIN-DEV          AGE
1     S    50:6b:4b:9b:82:c0   10   PortChannel2001     PortChannel2001     L
2     S    50:6b:4b:9b:82:c0   100  PortChannel2001     PortChannel2001     L
3     D    64:9d:99:17:cb:2c   100  PortChannel184      PortChannel184      P

$ show vlan brief
+-----------+------------------+-----------------+----------------+-------------+-----------------------+
|   VLAN ID | IP Address       | Ports           | Port Tagging   | Proxy ARP   | DHCP Helper Address   |
+===========+==================+=================+================+=============+=======================+
|        10 | 192.168.10.1/24  | PortChannel2001 | tagged         | disabled    |                       |
+-----------+------------------+-----------------+----------------+-------------+-----------------------+
|       100 | 192.168.100.1/24 | PortChannel184  | tagged         | disabled    |                       |
|           |                  | PortChannel2001 | tagged         |             |                       |
+-----------+------------------+-----------------+----------------+-------------+-----------------------+

$ show mac
  No.    Vlan  MacAddress         Port             Type
-----  ------  -----------------  ---------------  -------
    1      10  50:6B:4B:9B:82:C0  PortChannel2001  Static
    2     100  64:9D:99:17:CB:2C  PortChannel184   Dynamic
    3     100  50:6B:4B:9B:82:C0  PortChannel2001  Static

Runtime information for switch 2

$ show int portchannel
Flags: A - active, I - inactive, Up - up, Dw - Down, N/A - not available,
       S - selected, D - deselected, * - not synced
  No.  Team Dev         Protocol     Ports
-----  ---------------  -----------  -----------------------------
  176  PortChannel176   LACP(A)(Dw)  Ethernet176(S*)
  184  PortChannel184   LACP(A)(Up)  Ethernet184(S)
 2001  PortChannel2001  LACP(A)(Up)  Ethernet196(S) Ethernet192(S)

$ mclagdctl dump state
The MCLAG's keepalive is: OK
MCLAG info sync is: completed
Domain id: 1
Local Ip: 192.168.10.2
Peer Ip: 192.168.10.1
Peer Link Interface: PortChannel2001
Keepalive time: 1
sesssion Timeout : 15
Peer Link Mac: 50:6b:4b:9b:82:c0
Role: Standby
MCLAG Interface: PortChannel184
Loglevel: NOTICE

$ mclagdctl dump mac -i 1
TYPE: S-STATIC, D-DYNAMIC; AGE: L-Local age, P-Peer age
No.   TYPE MAC                 VID  DEV                 ORIGIN-DEV          AGE
1     S    04:3f:72:2f:38:00   10   PortChannel2001     PortChannel2001     L
2     S    04:3f:72:2f:38:00   100  PortChannel2001     PortChannel2001     L
3     D    64:9d:99:17:cb:2c   100  PortChannel184      PortChannel184      L

$ show vlan brief
+-----------+------------------+-----------------+----------------+-------------+-----------------------+
|   VLAN ID | IP Address       | Ports           | Port Tagging   | Proxy ARP   | DHCP Helper Address   |
+===========+==================+=================+================+=============+=======================+
|        10 | 192.168.10.2/24  | PortChannel2001 | tagged         | disabled    |                       |
+-----------+------------------+-----------------+----------------+-------------+-----------------------+
|       100 | 192.168.100.2/24 | PortChannel184  | tagged         | disabled    |                       |
|           |                  | PortChannel2001 | tagged         |             |                       |
+-----------+------------------+-----------------+----------------+-------------+-----------------------+

$ show mac
  No.    Vlan  MacAddress         Port             Type
-----  ------  -----------------  ---------------  ------
    1      10  04:3F:72:2F:38:00  PortChannel2001  Static
    2     100  04:3F:72:2F:38:00  PortChannel2001  Static
    3     100  64:9D:99:17:CB:2C  PortChannel184   Static
Total number of entries 3

Above states show switch-1 role is Active and switch-2 role is Standby. I assume my mc-lag configuration is correct at this moment.

Next I try to shutdown interface Ethernet184 of switch-2:

config int shutdown Ethernet184

After a while, few docker container crash and restarted. The mclag peering connections crash too. Those crash container/service will back online after some time.

This is the log captured during the crashing:


Sep 21 12:44:49.392405 sonic WARNING swss#orchagent: :- parsePortConfig: Unknown field(mode): skipping ...
Sep 21 12:44:49.392405 sonic INFO lldp#lldpmgrd[36]: Unable to retrieve description for port 'Ethernet184'. Not adding port description
Sep 21 12:44:49.398965 sonic NOTICE swss#portmgrd: :- doTask: Configure Ethernet184 MTU to 9100
Sep 21 12:44:49.406885 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_newlink.NOTICE] Update local port Ethernet184 state down
Sep 21 12:44:49.406885 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_deladdr.NOTICE] l3_proto 0, ifname Ethernet184 index 1689 is_vrf 0 address fe80::63f:72ff:fe2f:3800
Sep 21 12:44:49.406885 sonic NOTICE swss#portsyncd: :- onMsg: nlmsg type:16 key:Ethernet184 admin:0 oper:0 addr:04:3f:72:2f:38:00 ifindex:1689 master:1601 type:sx_netdev
Sep 21 12:44:49.406885 sonic NOTICE swss#portmgrd: :- doTask: Configure Ethernet184 admin status to down
Sep 21 12:44:49.406885 sonic NOTICE swss#portsyncd: :- onMsg: Publish Ethernet184(ok:down) to state db
Sep 21 12:44:49.406885 sonic NOTICE swss#portsyncd: :- onMsg: nlmsg type:16 key:Ethernet184 admin:0 oper:0 addr:04:3f:72:2f:38:00 ifindex:1689 master:1601 type:sx_netdev
Sep 21 12:44:49.415814 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_newlink.NOTICE] Update local port PortChannel184 state down
Sep 21 12:44:49.416580 sonic INFO kernel: [94358.277233] Bridge: port 3(PortChannel184) entered disabled state
Sep 21 12:44:49.424011 sonic WARNING swss#orchagent: message repeated 2 times: [ :- parsePortConfig: Unknown field(mode): skipping ...]
Sep 21 12:44:49.424011 sonic NOTICE swss#orchagent: :- setPortAdminStatus: Set admin status DOWN host_tx_ready to false for port Ethernet184
Sep 21 12:44:49.424011 sonic NOTICE iccpd#mclagsyncd: :- setFdbEntry: add fdb entry into ASIC_DB:key =Vlan100:64:9d:99:17:cb:2c, type =dynamic
Sep 21 12:44:49.431302 sonic NOTICE swss#portsyncd: :- onMsg: Publish Ethernet184(ok:down) to state db
Sep 21 12:44:49.431302 sonic NOTICE swss#portsyncd: :- onMsg: nlmsg type:16 key:Ethernet184 admin:0 oper:0 addr:04:3f:72:2f:38:00 ifindex:1689 master:1601 type:sx_netdev
Sep 21 12:44:49.431302 sonic NOTICE iccpd#mclagsyncd: :- mclagsyncdSetTrafficDisable: Set traffic disable for PortChannel184
Sep 21 12:44:49.431302 sonic NOTICE syncd#SDK: [SAI_UTILS.NOTICE] ./src/mlnx_sai_utils.c[1911]- set_dispatch_attrib_handler: Set ADMIN_STATE, key:PORT [OID:0x1000F00000001] [log_port:0x1000F], val:false
Sep 21 12:44:49.437820 sonic NOTICE swss#portsyncd: :- onMsg: Publish Ethernet184(ok:down) to state db
Sep 21 12:44:49.437820 sonic NOTICE syncd#SDK: [SAI_SWITCH.NOTICE] ./src/mlnx_sai_switch.c[6689]- event_thread_func: Port 1000f changed state to down
Sep 21 12:44:49.437820 sonic NOTICE swss#portsyncd: :- onMsg: nlmsg type:16 key:PortChannel184 admin:1 oper:0 addr:04:3f:72:2f:38:00 ifindex:1601 master:1578
Sep 21 12:44:49.437820 sonic NOTICE swss#portsyncd: :- onMsg: Cannot find PortChannel184 in port table
Sep 21 12:44:49.437820 sonic NOTICE swss#portsyncd: :- onMsg: nlmsg type:16 key:PortChannel184 admin:1 oper:0 addr:04:3f:72:2f:38:00 ifindex:1601 master:1578 type:team
Sep 21 12:44:49.440725 sonic NOTICE kernel: [94358.300817] Called for logical port - 1000F status DOWN
Sep 21 12:44:49.441977 sonic NOTICE bgp#fpmsyncd: message repeated 2 times: [ :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fe80::/64 :: eth0 ]
Sep 21 12:44:49.441977 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: 0.0.0.0/0 192.168.0.1 eth0
Sep 21 12:44:49.441977 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: ::/0 fe80::21b:21ff:febe:2f0 eth0
Sep 21 12:44:49.441977 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fd00::/80 :: docker0
Sep 21 12:44:49.441977 sonic NOTICE swss#orchagent: :- doPortTask: Set port Ethernet184 admin status to down
Sep 21 12:44:49.441977 sonic NOTICE swss#orchagent: :- doTask: Get port state change notification id:1000000000408 status:2
Sep 21 12:44:49.441977 sonic NOTICE swss#orchagent: :- updatePortOperStatus: Port Ethernet184 oper state set from up to down
Sep 21 12:44:49.441977 sonic NOTICE syncd#SDK: [SAI_UTILS.NOTICE] ./src/mlnx_sai_utils.c[1911]- set_dispatch_attrib_handler: Set OPER_STATUS, key:HOSTIF [OID:0x2E0000000D] [hostif_db[46]], val:false
Sep 21 12:44:49.446311 sonic INFO lldp#lldpmgrd[36]: Unable to retrieve description for port 'Ethernet184'. Not adding port description
Sep 21 12:44:49.446311 sonic INFO lldp#lldpmgrd[36]: port Ethernet184 is not up, continue
Sep 21 12:44:49.446311 sonic INFO lldp#lldpmgrd[36]: Unable to retrieve description for port 'Ethernet184'. Not adding port description
Sep 21 12:44:49.452424 sonic INFO lldp#lldpmgrd[36]: port Ethernet184 is not up, continue
Sep 21 12:44:49.452651 sonic INFO lldp#lldpmgrd[36]: Unable to retrieve description for port 'Ethernet184'. Not adding port description
Sep 21 12:44:49.452827 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fe80::/64 :: eth0
Sep 21 12:44:49.453029 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: 0.0.0.0/0 192.168.0.1 eth0
Sep 21 12:44:49.453185 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: ::/0 fe80::21b:21ff:febe:2f0 eth0
Sep 21 12:44:49.453354 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fd00::/80 :: docker0
Sep 21 12:44:49.461411 sonic NOTICE swss#orchagent: :- setHostIntfsOperStatus: Set operation status DOWN to host interface Ethernet184
Sep 21 12:44:49.461411 sonic NOTICE swss#orchagent: :- publish: EVENT_PUBLISHED: {"sonic-events-swss:if-state":{"ifname":"Ethernet184","status":"down","timestamp":"2023-09-21T12:44:49.450308Z"}}
Sep 21 12:44:49.461411 sonic WARNING swss#orchagent: :- flushFDBEntries: Couldn't flush FDB. Bridge port OID: 0x0 bvid:0,
Sep 21 12:44:49.461411 sonic INFO lldp#lldpmgrd[36]: port Ethernet184 is not up, continue
Sep 21 12:44:49.461411 sonic INFO lldp#lldpmgrd[36]: Unable to retrieve description for port 'Ethernet184'. Not adding port description
Sep 21 12:44:49.461411 sonic INFO lldp#lldpmgrd[36]: port Ethernet184 is not up, continue
Sep 21 12:44:49.461411 sonic INFO lldp#lldpmgrd[36]: Unable to retrieve description for port 'Ethernet184'. Not adding port description
Sep 21 12:44:49.461411 sonic INFO lldp#lldpmgrd[36]: port Ethernet184 is not up, continue
Sep 21 12:44:49.461411 sonic NOTICE syncd#SDK: [SAI_UTILS.NOTICE] ./src/mlnx_sai_utils.c[1911]- set_dispatch_attrib_handler: Set EGRESS_DISABLE, key:LAG_MEMBER [OID:0x1000F0001001B] [log_port:0x1000F, lag_log_id:0x1], val:true
Sep 21 12:44:49.482347 sonic NOTICE swss#orchagent: :- setDistributionOnLagMember: Disable distribution on LAG member Ethernet184
Sep 21 12:44:49.482347 sonic NOTICE syncd#SDK: [SAI_UTILS.NOTICE] ./src/mlnx_sai_utils.c[1911]- set_dispatch_attrib_handler: Set INGRESS_DISABLE, key:LAG_MEMBER [OID:0x1000F0001001B] [log_port:0x1000F, lag_log_id:0x1], val:true
Sep 21 12:44:49.482347 sonic NOTICE swss#orchagent: :- setCollectionOnLagMember: Disable collection on LAG member Ethernet184
Sep 21 12:44:49.489985 sonic NOTICE swss#orchagent: :- updatePortOperStatus: Port PortChannel184 oper state set from up to down
Sep 21 12:44:49.489985 sonic NOTICE swss#orchagent: :- flushFdbEntries: flush key: SAI_OBJECT_TYPE_FDB_FLUSH:oid:0x21000000000000, fields: 2
Sep 21 12:44:49.489985 sonic NOTICE swss#orchagent: :- recordFlushFdbEntries: flush key: SAI_OBJECT_TYPE_FDB_FLUSH:oid:0x21000000000000, fields: 2
Sep 21 12:44:49.508641 sonic NOTICE syncd#SDK: [SAI_FDB.NOTICE] ./src/mlnx_sai_fdb.c[1425]- mlnx_flush_fdb_entries: Create FDB_FLUSH: #0 BRIDGE_PORT_ID=BRIDGE_PORT [OID:0x10000003A] [bridge_ports_db[1]] #1 ENTRY_TYPE=DYNAMIC
Sep 21 12:44:49.514402 sonic NOTICE syncd#SDK: :- processFdbFlush: fdb flush succeeded, updating redis database
Sep 21 12:44:49.514402 sonic NOTICE syncd#SDK: :- processFlushEvent: received a flush port fdb event, portVid = oid:0x3a0000000009b8, bvId = oid:0x0
Sep 21 12:44:49.514402 sonic NOTICE syncd#SDK: :- processFlushEvent: pattern ASIC_STATE:SAI_OBJECT_TYPE_FDB_ENTRY:*, portStr oid:0x3a0000000009b8
Sep 21 12:44:49.514402 sonic NOTICE swss#orchagent: :- meta_sai_on_fdb_flush_event_consolidated: processing consolidated fdb flush event of type: SAI_FDB_ENTRY_TYPE_DYNAMIC
Sep 21 12:44:49.514402 sonic NOTICE swss#orchagent: :- meta_sai_on_fdb_flush_event_consolidated: fdb flush took 0.000468 sec
Sep 21 12:44:49.514402 sonic NOTICE syncd#SDK: :- handle_fdb_event: got fdb flush event: [{"fdb_entry":"{\"bvid\":\"oid:0x0\",\"mac\":\"00:00:00:00:00:00\",\"switch_id\":\"oid:0x100000021\"}","fdb_event":"SAI_FDB_EVENT_FLUSHED","list":[{"id":"SAI_FDB_ENTRY_ATTR_BRIDGE_PORT_ID","value":"oid:0x10000003a"},{"id":"SAI_FDB_ENTRY_ATTR_TYPE","value":"SAI_FDB_ENTRY_TYPE_DYNAMIC"},{"id":"SAI_FDB_ENTRY_ATTR_PACKET_ACTION","value":"SAI_PACKET_ACTION_FORWARD"}]}]
Sep 21 12:44:49.514402 sonic NOTICE syncd#SDK: :- processFlushEvent: received a flush port fdb event, portVid = oid:0x3a0000000009b8, bvId = oid:0x0
Sep 21 12:44:49.514402 sonic NOTICE syncd#SDK: :- processFlushEvent: pattern ASIC_STATE:SAI_OBJECT_TYPE_FDB_ENTRY:*, portStr oid:0x3a0000000009b8
Sep 21 12:44:49.599313 sonic NOTICE syncd#SDK: [SAI_UTILS.NOTICE] ./src/mlnx_sai_utils.c[1911]- set_dispatch_attrib_handler: Set PACKET_ACTION, key:ROUTE_ENTRY :: ::, val:DROP
Sep 21 12:44:49.599313 sonic NOTICE syncd#SDK: [SAI_UTILS.NOTICE] ./src/mlnx_sai_utils.c[1911]- set_dispatch_attrib_handler: Set PACKET_ACTION, key:ROUTE_ENTRY 0.0.0.0 0.0.0.0, val:DROP
Sep 21 12:44:49.599313 sonic NOTICE syncd#SDK: [SAI_UTILS.NOTICE] ./src/mlnx_sai_utils.c[2319]- mlnx_bulk_statuses_print: [BULK_SET] 4 Routes: 4 success, 0 not executed, 0 failed
Sep 21 12:44:49.608331 sonic NOTICE swss#orchagent: :- meta_sai_on_fdb_flush_event_consolidated: processing consolidated fdb flush event of type: SAI_FDB_ENTRY_TYPE_DYNAMIC
Sep 21 12:44:49.608331 sonic NOTICE swss#orchagent: :- meta_sai_on_fdb_flush_event_consolidated: fdb flush took 0.000339 sec
Sep 21 12:44:49.636590 sonic NOTICE syncd#SDK: [SAI_UTILS.NOTICE] ./src/mlnx_sai_utils.c[1911]- set_dispatch_attrib_handler: Set TYPE, key:FDB_ENTRY [64:9d:99:17:cb:2c] [BV_ID:0x6400000026], val:STATIC
Sep 21 12:44:49.637124 sonic ERR syncd#SDK: [SAI_FDB.ERR] ./src/mlnx_sai_fdb.c[446]- mlnx_get_mac: Failed to get 0 fdb entries Entry Not Found.
Sep 21 12:44:49.637483 sonic ERR syncd#SDK: [SAI_UTILS.ERR] ./src/mlnx_sai_utils.c[1914]- set_dispatch_attrib_handler: Failed Set TYPE, key:FDB_ENTRY [64:9d:99:17:cb:2c] [BV_ID:0x6400000026], val:STATIC
Sep 21 12:44:49.637787 sonic ERR syncd#SDK: [SAI_UTILS.ERR] ./src/mlnx_sai_utils.c[2134]- sai_set_attribute: Failed to set the attribute.
Sep 21 12:44:49.638516 sonic ERR syncd#SDK: :- sendApiResponse: api SAI_COMMON_API_SET failed in syncd mode: SAI_STATUS_ITEM_NOT_FOUND
Sep 21 12:44:49.638516 sonic ERR syncd#SDK: :- processQuadEvent: attr: SAI_FDB_ENTRY_ATTR_TYPE: SAI_FDB_ENTRY_TYPE_STATIC
Sep 21 12:44:49.639377 sonic ERR swss#orchagent: :- set: set status: SAI_STATUS_ITEM_NOT_FOUND
Sep 21 12:44:49.640152 sonic ERR swss#orchagent: :- addFdbEntry: macUpdate-Failed for attr.id=0x0 for FDB 64:9d:99:17:cb:2c in Vlan100 on PortChannel2001, rv:-7
Sep 21 12:44:49.640152 sonic ERR swss#orchagent: :- handleSaiSetStatus: Encountered failure in set operation, exiting orchagent, SAI API: SAI_API_FDB, status: SAI_STATUS_ITEM_NOT_FOUND
Sep 21 12:44:49.640152 sonic NOTICE swss#orchagent: :- notifySyncd: sending syncd: SYNCD_INVOKE_DUMP
Sep 21 12:44:49.640976 sonic NOTICE syncd#SDK: :- processNotifySyncd: Invoking SAI failure dump
Sep 21 12:44:49.678566 sonic INFO syncd#SDK: [LOG.INFO] Initializing SX log with user callback function.
Sep 21 12:44:49.690028 sonic NOTICE syncd#SDK: [DBG.NOTICE] Started DEBUG-DUMP
Sep 21 12:44:49.690996 sonic NOTICE syncd#SDK: [EMAD.NOTICE] setting emad-timeout to 1000000
Sep 21 12:44:50.050560 sonic NOTICE syncd#SDK: :- threadFunction: time span 409 ms for 'notify:SYNCD_INVOKE_DUMP'
Sep 21 12:44:51.050690 sonic NOTICE syncd#SDK: :- threadFunction: time span 1409 ms for 'notify:SYNCD_INVOKE_DUMP'
Sep 21 12:44:51.696899 sonic INFO systemd[1]: run-docker-runtime\x2drunc-moby-b08e3c24fd0869e6085e9476afff40e4ae88f12512be34edacf1be374a081168-runc.NTc3tx.mount: Succeeded.
Sep 21 12:44:52.050877 sonic NOTICE syncd#SDK: :- threadFunction: time span 2409 ms for 'notify:SYNCD_INVOKE_DUMP'
Sep 21 12:44:53.051192 sonic NOTICE syncd#SDK: :- threadFunction: time span 3409 ms for 'notify:SYNCD_INVOKE_DUMP'
Sep 21 12:44:53.292297 sonic NOTICE syncd#SDK: [EMAD.NOTICE] setting emad-timeout to 20000000
Sep 21 12:44:53.292498 sonic NOTICE syncd#SDK: [DBG.NOTICE] Finished DEBUG-DUMP
Sep 21 12:44:54.051070 sonic NOTICE syncd#SDK: :- threadFunction: time span 4410 ms for 'notify:SYNCD_INVOKE_DUMP'
Sep 21 12:44:54.939369 sonic NOTICE syncd#SDK: [COMMAND_IFC.NOTICE] COMMAND IFC:   COMMAND IFC INIT DONE
Sep 21 12:44:54.951600 sonic NOTICE syncd#SDK: [ACCESS_REG_INIT.NOTICE] ACCESS REG:   ACCESS REG INIT DONE
Sep 21 12:44:55.027014 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] Generating 3 CR-Space dumps
Sep 21 12:44:55.027444 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] FW dump using temporary file (/var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sdkdump_ext_meta_001-21_09_2023-04_44_55-26845iicobztbn.tmp).
Sep 21 12:44:55.027768 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] FW dump using temporary file (/var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sdkdump_ext_cr_001-21_09_2023-04_44_55-26845.udmprvqwkoqsm.tmp).
Sep 21 12:44:55.028048 sonic NOTICE syncd#SDK: [SXD_FW_DBG.NOTICE] sxd_fw_dbg_extract FW instruction structure for type:[8] not yet initialized, trying to initialize it now
Sep 21 12:44:55.028406 sonic NOTICE syncd#SDK: [SXD_FW_DBG.NOTICE] file:[Spectrum.csv] lines:[22359]
Sep 21 12:44:55.031503 sonic NOTICE syncd#SDK: [SXD_FW_DBG.NOTICE] file:[Spectrum.csv] parsing done
Sep 21 12:44:55.051145 sonic NOTICE syncd#SDK: :- threadFunction: time span 5410 ms for 'notify:SYNCD_INVOKE_DUMP'
Sep 21 12:44:55.368815 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] SDK extra dump meta file saved to:[/var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sdkdump_ext_meta_001-21_09_2023-04_44_55-26845]
Sep 21 12:44:55.369248 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] SDK extra dump file CR saved to:[/var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sdkdump_ext_cr_001-21_09_2023-04_44_55-26845.udmp]
Sep 21 12:44:55.369566 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] FW dump using temporary file (/var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sdkdump_ext_meta_001-21_09_2023-04_44_55-368629wcpsgesme.tmp).
Sep 21 12:44:55.369830 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] FW dump using temporary file (/var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sdkdump_ext_cr_001-21_09_2023-04_44_55-368629.udmprprnbarqb.tmp).
Sep 21 12:44:55.370084 sonic NOTICE syncd#SDK: [SXD_FW_DBG.NOTICE] sxd_fw_dbg_extract FW instruction structure for type:[8] not yet initialized, trying to initialize it now
Sep 21 12:44:55.370329 sonic NOTICE syncd#SDK: [SXD_FW_DBG.NOTICE] file:[Spectrum.csv] lines:[22359]
Sep 21 12:44:55.373346 sonic NOTICE syncd#SDK: [SXD_FW_DBG.NOTICE] file:[Spectrum.csv] parsing done
Sep 21 12:44:55.716589 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] SDK extra dump meta file saved to:[/var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sdkdump_ext_meta_001-21_09_2023-04_44_55-368629]
Sep 21 12:44:55.717037 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] SDK extra dump file CR saved to:[/var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sdkdump_ext_cr_001-21_09_2023-04_44_55-368629.udmp]
Sep 21 12:44:55.717376 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] FW dump using temporary file (/var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sdkdump_ext_meta_001-21_09_2023-04_44_55-716450cunjkhyeo.tmp).
Sep 21 12:44:55.717687 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] FW dump using temporary file (/var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sdkdump_ext_cr_001-21_09_2023-04_44_55-716450.udmpajsfiuuba.tmp).
Sep 21 12:44:55.717956 sonic NOTICE syncd#SDK: [SXD_FW_DBG.NOTICE] sxd_fw_dbg_extract FW instruction structure for type:[8] not yet initialized, trying to initialize it now
Sep 21 12:44:55.718200 sonic NOTICE syncd#SDK: [SXD_FW_DBG.NOTICE] file:[Spectrum.csv] lines:[22359]
Sep 21 12:44:55.721153 sonic NOTICE syncd#SDK: [SXD_FW_DBG.NOTICE] file:[Spectrum.csv] parsing done
Sep 21 12:44:56.057476 sonic NOTICE syncd#SDK: :- threadFunction: time span 6416 ms for 'notify:SYNCD_INVOKE_DUMP'
Sep 21 12:44:56.072584 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] SDK extra dump meta file saved to:[/var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sdkdump_ext_meta_001-21_09_2023-04_44_55-716450]
Sep 21 12:44:56.073155 sonic NOTICE syncd#SDK: [SX_API_DBG.NOTICE] SDK extra dump file CR saved to:[/var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sdkdump_ext_cr_001-21_09_2023-04_44_55-716450.udmp]
Sep 21 12:44:56.073761 sonic NOTICE syncd#SDK: [SX_API_DBG_AMBER.NOTICE] AMBER Dump: Starting dump process to file /var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/amber_dump_001-21_09_2023-04_44_56.hex
Sep 21 12:44:56.074267 sonic NOTICE syncd#SDK: [EMAD.NOTICE] setting emad-timeout to 1000000
Sep 21 12:44:57.057652 sonic NOTICE syncd#SDK: :- threadFunction: time span 7416 ms for 'notify:SYNCD_INVOKE_DUMP'
Sep 21 12:44:57.245762 sonic NOTICE syncd#SDK: [EMAD.NOTICE] setting emad-timeout to 20000000
Sep 21 12:44:57.248532 sonic NOTICE syncd#SDK: [SAI_SWITCH.NOTICE] ./src/mlnx_sai_switch.c[5444]- mlnx_switch_dfw_thread_func: DFW thread got completed async dump.
Sep 21 12:44:57.249065 sonic NOTICE syncd#SDK: :- main: The SAI dump is generated to /var/log/sai_failure_dump/sai_sdk_dump_09_21_2023_04_44_AM/sai_sdk_dump_09_21_2023_04_44_AM .
Sep 21 12:44:57.488669 sonic INFO syncd#supervisord 2023-09-21 04:44:57,487 INFO reaped unknown pid 608 (exit status 0)
Sep 21 12:44:58.057743 sonic NOTICE syncd#SDK: :- threadFunction: time span 8416 ms for 'notify:SYNCD_INVOKE_DUMP'
Sep 21 12:44:58.856789 sonic INFO systemd[1]: run-docker-runtime\x2drunc-moby-b08e3c24fd0869e6085e9476afff40e4ae88f12512be34edacf1be374a081168-runc.bqhVH7.mount: Succeeded.
Sep 21 12:44:59.057870 sonic NOTICE syncd#SDK: :- threadFunction: time span 9416 ms for 'notify:SYNCD_INVOKE_DUMP'
Sep 21 12:44:59.157233 sonic NOTICE swss#orchagent: :- sai_redis_notify_syncd: invoked DUMP succeeded
Sep 21 12:45:01.453593 sonic INFO swss#supervisord 2023-09-21 12:45:01,452 INFO exited: orchagent (terminated by SIGABRT (core dumped); not expected)
Sep 21 12:45:02.460844 sonic INFO swss#supervisor-proc-exit-listener: Process 'orchagent' exited unexpectedly. Terminating supervisor 'swss'
Sep 21 12:45:02.462097 sonic NOTICE swss#supervisor-proc-exit-listener: :- publish: EVENT_PUBLISHED: {"sonic-events-host:process-exited-unexpectedly":{"ctr_name":"swss","process_name":"orchagent","timestamp":"2023-09-21T12:45:02.461532Z"}}
Sep 21 12:45:02.465331 sonic INFO swss#supervisord 2023-09-21 12:45:02,464 WARN received SIGTERM indicating exit request
Sep 21 12:45:02.466432 sonic INFO swss#supervisord 2023-09-21 12:45:02,465 INFO waiting for supervisor-proc-exit-listener, rsyslogd, portsyncd, coppmgrd, arp_update, ndppd, neighsyncd, vlanmgrd, intfmgrd, portmgrd, buffermgrd, vrfmgrd, nbrmgrd, vxlanmgrd, fdbsyncd, tunnelmgrd, containercfgd to die
Sep 21 12:45:02.509755 sonic INFO swss#supervisord 2023-09-21 12:45:02,508 INFO stopped: containercfgd (exit status 143)
Sep 21 12:45:02.512769 sonic INFO swss#supervisord 2023-09-21 12:45:02,511 INFO stopped: tunnelmgrd (terminated by SIGTERM)
Sep 21 12:45:02.521225 sonic INFO swss#supervisord 2023-09-21 12:45:02,518 INFO stopped: fdbsyncd (terminated by SIGTERM)
Sep 21 12:45:02.528158 sonic INFO swss#supervisord 2023-09-21 12:45:02,526 INFO stopped: vxlanmgrd (terminated by SIGTERM)
Sep 21 12:45:02.543398 sonic INFO swss#supervisord 2023-09-21 12:45:02,538 INFO stopped: nbrmgrd (terminated by SIGTERM)
Sep 21 12:45:02.549870 sonic INFO swss#supervisord 2023-09-21 12:45:02,547 INFO stopped: vrfmgrd (terminated by SIGTERM)
Sep 21 12:45:03.555502 sonic INFO swss#supervisord 2023-09-21 12:45:03,554 INFO stopped: buffermgrd (terminated by SIGTERM)
Sep 21 12:45:03.558365 sonic INFO swss#supervisord 2023-09-21 12:45:03,557 INFO stopped: portmgrd (terminated by SIGTERM)
Sep 21 12:45:03.569065 sonic INFO swss#supervisord 2023-09-21 12:45:03,566 INFO stopped: intfmgrd (terminated by SIGTERM)
Sep 21 12:45:03.573656 sonic INFO swss#supervisord 2023-09-21 12:45:03,572 INFO stopped: vlanmgrd (terminated by SIGTERM)
Sep 21 12:45:04.579073 sonic INFO swss#supervisord 2023-09-21 12:45:04,575 INFO stopped: neighsyncd (terminated by SIGTERM)
Sep 21 12:45:04.579073 sonic INFO swss#supervisord: orchagent
Sep 21 12:45:04.579073 sonic INFO swss#supervisord: ndppd (error) Shutting down...
Sep 21 12:45:04.579073 sonic INFO swss#supervisord: ndppd (notice) Bye
Sep 21 12:45:04.579073 sonic INFO swss#supervisord 2023-09-21 12:45:04,577 INFO stopped: ndppd (exit status 0)
Sep 21 12:45:05.583063 sonic INFO swss#supervisord 2023-09-21 12:45:05,580 INFO stopped: arp_update (terminated by SIGTERM)
Sep 21 12:45:05.585256 sonic INFO swss#supervisord 2023-09-21 12:45:05,581 INFO waiting for supervisor-proc-exit-listener, rsyslogd, portsyncd, coppmgrd to die
Sep 21 12:45:05.586518 sonic INFO swss#supervisord 2023-09-21 12:45:05,585 INFO stopped: coppmgrd (terminated by SIGTERM)
Sep 21 12:45:06.198351 sonic INFO systemd[1]: run-docker-runtime\x2drunc-moby-b08e3c24fd0869e6085e9476afff40e4ae88f12512be34edacf1be374a081168-runc.4EMsr5.mount: Succeeded.
Sep 21 12:45:07.591907 sonic INFO swss#supervisord 2023-09-21 12:45:07,591 INFO stopped: portsyncd (terminated by SIGTERM)
Sep 21 12:45:08.700391 sonic INFO dockerd[589]: time="2023-09-21T12:45:08.699315085+08:00" level=info msg="ignoring event" container=fe2448156c117fd686f851337f1fd88e58e19fa0f97a22fd20bec3823cd7b4f6 module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
Sep 21 12:45:08.701799 sonic INFO containerd[391]: time="2023-09-21T12:45:08.701079351+08:00" level=info msg="shim disconnected" id=fe2448156c117fd686f851337f1fd88e58e19fa0f97a22fd20bec3823cd7b4f6
Sep 21 12:45:08.702872 sonic INFO containerd[391]: time="2023-09-21T12:45:08.702746606+08:00" level=warning msg="cleaning up after shim disconnected" id=fe2448156c117fd686f851337f1fd88e58e19fa0f97a22fd20bec3823cd7b4f6 namespace=moby
Sep 21 12:45:08.704096 sonic INFO containerd[391]: time="2023-09-21T12:45:08.703963317+08:00" level=info msg="cleaning up dead shim"
Sep 21 12:45:08.723691 sonic INFO containerd[391]: time="2023-09-21T12:45:08.723543714+08:00" level=warning msg="cleanup warnings time=\"2023-09-21T12:45:08+08:00\" level=info msg=\"starting signal loop\" namespace=moby pid=1180676 runtime=io.containerd.runc.v2\n"
Sep 21 12:45:08.778711 sonic INFO systemd[1]: var-lib-docker-overlay2-ac413ee3a30b27f1629731ffae06e1abc8e670180db7345cdf0d02762951ee31-merged.mount: Succeeded.
Sep 21 12:45:09.894299 sonic NOTICE root: Stopping swss service...
Sep 21 12:45:09.906223 sonic NOTICE root: Locking /tmp/swss-syncd-lock from swss service
Sep 21 12:45:09.921137 sonic NOTICE root: Locked /tmp/swss-syncd-lock (10) from swss service
Sep 21 12:45:09.969771 sonic NOTICE root: Warm boot flag: swss false.
Sep 21 12:45:09.999423 sonic NOTICE root: Fast boot flag: swss false.
Sep 21 12:45:10.764508 sonic DEBUG container: container_stop: BEGIN
Sep 21 12:45:10.767557 sonic DEBUG container: read_data: config:True feature:swss fields:[('set_owner', 'local'), ('no_fallback_to_local', False), ('state', 'disabled')] val:['local', False, 'enabled']
Sep 21 12:45:10.769056 sonic DEBUG container: read_data: config:False feature:swss fields:[('current_owner', 'none'), ('remote_state', 'none'), ('container_id', '')] val:['none', 'none', '']
Sep 21 12:45:10.770686 sonic DEBUG container: container_stop: swss: set_owner:local current_owner:none remote_state:none docker_id:swss
Sep 21 12:45:10.796449 sonic INFO container: docker cmd: stop for swss
Sep 21 12:45:10.797910 sonic DEBUG container: container_stop: END
Sep 21 12:45:10.904813 sonic NOTICE root: Stopped swss service...
Sep 21 12:45:10.938173 sonic INFO swss.sh[1180903]: 1
Sep 21 12:45:10.944386 sonic NOTICE root: Cleared PortInitDone from APPL_DB...
Sep 21 12:45:10.959347 sonic NOTICE root: Clearing FAST_RESTART_ENABLE_TABLE flag...
Sep 21 12:45:10.998142 sonic INFO swss.sh[1180911]: 0
Sep 21 12:45:11.005403 sonic NOTICE root: Unlocking /tmp/swss-syncd-lock (10) from swss service
Sep 21 12:45:11.036538 sonic INFO systemd[1]: Stopping TEAMD container...
Sep 21 12:45:11.046041 sonic NOTICE admin: Stopping teamd service...
Sep 21 12:45:11.116432 sonic NOTICE admin: Warm boot flag: teamd false.
Sep 21 12:45:11.130485 sonic NOTICE admin: Fast boot flag: teamd false.
Sep 21 12:45:12.036794 sonic DEBUG container: container_stop: BEGIN
Sep 21 12:45:12.039622 sonic DEBUG container: read_data: config:True feature:teamd fields:[('set_owner', 'local'), ('no_fallback_to_local', False), ('state', 'disabled')] val:['local', False, 'enabled']
Sep 21 12:45:12.040500 sonic DEBUG container: read_data: config:False feature:teamd fields:[('current_owner', 'none'), ('remote_state', 'none'), ('container_id', '')] val:['none', 'none', '']
Sep 21 12:45:12.042923 sonic DEBUG container: container_stop: teamd: set_owner:local current_owner:none remote_state:none docker_id:teamd
Sep 21 12:45:12.900810 sonic INFO teamd#supervisord 2023-09-21 12:45:12,896 WARN received SIGTERM indicating exit request
Sep 21 12:45:12.902232 sonic INFO teamd#supervisord 2023-09-21 12:45:12,901 INFO waiting for supervisor-proc-exit-listener, rsyslogd, teammgrd, teamsyncd, tlm_teamd, containercfgd to die
Sep 21 12:45:13.929645 sonic INFO teamd#supervisord 2023-09-21 12:45:13,928 INFO stopped: containercfgd (exit status 143)
Sep 21 12:45:14.931958 sonic NOTICE teamd#tlm_teamd: :- main: Exiting
Sep 21 12:45:14.933448 sonic NOTICE teamd#tlm_teamd: :- ~TeamdCtlMgr: Exiting. Disconnecting from teamd. LAG 'PortChannel2001'
Sep 21 12:45:14.933448 sonic NOTICE teamd#tlm_teamd: :- ~TeamdCtlMgr: Exiting. Disconnecting from teamd. LAG 'PortChannel184'
Sep 21 12:45:14.933448 sonic NOTICE teamd#tlm_teamd: :- ~TeamdCtlMgr: Exiting. Disconnecting from teamd. LAG 'PortChannel176'
Sep 21 12:45:15.409088 sonic INFO teamd#supervisord 2023-09-21 12:45:15,408 INFO stopped: tlm_teamd (exit status 0)
Sep 21 12:45:16.411960 sonic INFO teamd#supervisord 2023-09-21 12:45:16,409 INFO waiting for supervisor-proc-exit-listener, rsyslogd, teammgrd, teamsyncd to die
Sep 21 12:45:16.411960 sonic NOTICE teamd#teamsyncd: :- cleanTeamSync: Cleaning up LAG teamd resources ...
Sep 21 12:45:16.412416 sonic NOTICE teamd#teamsyncd: :- main: Received SIGTERM Exiting
Sep 21 12:45:16.972034 sonic INFO teamd#supervisord 2023-09-21 12:45:16,971 INFO stopped: teamsyncd (exit status 0)
Sep 21 12:45:17.973866 sonic NOTICE teamd#teammgrd: :- cleanTeamProcesses: Cleaning up LAGs during shutdown...
Sep 21 12:45:17.979810 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_newlink.NOTICE] Update local port PortChannel176 state down
Sep 21 12:45:17.980172 sonic NOTICE iccpd#mclagsyncd: :- mclagsyncdSetTrafficDisable: Set traffic disable for PortChannel176
Sep 21 12:45:17.980363 sonic INFO kernel: [94386.842029] Bridge: port 2(PortChannel176) entered disabled state
Sep 21 12:45:17.984475 sonic INFO kernel: [94386.843810] device Ethernet176 left promiscuous mode
Sep 21 12:45:17.984781 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_newlink.NOTICE] Update local port Ethernet176 state down
Sep 21 12:45:17.985264 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_deladdr.NOTICE] l3_proto 0, ifname Ethernet176 index 1687 is_vrf 0 address fe80::526b:4bff:fe9b:82c0
Sep 21 12:45:17.985724 sonic NOTICE iccpd#mclagsyncd: :- setPortIsolate: set port isolate, src port: PortChannel2001, dst port: PortChannel184,Ethernet184,PortChannel176
Sep 21 12:45:17.988320 sonic INFO kernel: [94386.849349] PortChannel176: Port device Ethernet176 removed
Sep 21 12:45:17.991548 sonic NOTICE teamd#teammgrd: :- cleanTeamProcesses: Sent SIGTERM to port channel PortChannel176 pid 28
Sep 21 12:45:17.994364 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_deladdr.NOTICE] l3_proto 0, ifname PortChannel176 index 1592 is_vrf 0 address fe80::63f:72ff:fe2f:3800
Sep 21 12:45:17.996502 sonic INFO kernel: [94386.857095] Bridge: port 2(PortChannel176) entered disabled state
Sep 21 12:45:17.997733 sonic WARNING iccpd#iccpd: [local_if_destroy.WARN] Destroy interface PortChannel176, 1592
Sep 21 12:45:17.998093 sonic NOTICE iccpd#iccpd: [local_if_del_all_vlan.NOTICE] Remove all VLANs from PortChannel176
Sep 21 12:45:17.998300 sonic NOTICE iccpd#mclagsyncd: :- mclagsyncdSetTrafficDisable: Set traffic enable for PortChannel176
Sep 21 12:45:18.000366 sonic INFO kernel: [94386.860007] device PortChannel176 left promiscuous mode
Sep 21 12:45:18.000395 sonic INFO kernel: [94386.860034] Bridge: port 2(PortChannel176) entered disabled state
Sep 21 12:45:18.004471 sonic NOTICE teamd#teammgrd: :- cleanTeamProcesses: Sent SIGTERM to port channel PortChannel184 pid 36
Sep 21 12:45:18.009245 sonic NOTICE teamd#teammgrd: :- cleanTeamProcesses: Sent SIGTERM to port channel PortChannel2001 pid 44
Sep 21 12:45:18.009562 sonic NOTICE teamd#teammgrd: :- cleanTeamProcesses: Waiting for port channel PortChannel2001 pid 44 to stop...
Sep 21 12:45:18.030587 sonic INFO kernel: [94386.888742] device Ethernet184 left promiscuous mode
Sep 21 12:45:18.030614 sonic INFO kernel: [94386.893048] PortChannel184: Port device Ethernet184 removed
Sep 21 12:45:18.030645 sonic NOTICE iccpd#mclagsyncd: :- setPortIsolate: set port isolate, src port: PortChannel2001, dst port: PortChannel184
Sep 21 12:45:18.043298 sonic INFO kernel: [94386.898234] device Ethernet196 left promiscuous mode
Sep 21 12:45:18.043323 sonic INFO kernel: [94386.901426] PortChannel2001: Port device Ethernet196 removed
Sep 21 12:45:18.043326 sonic INFO kernel: [94386.902726] Bridge: port 4(PortChannel2001) entered disabled state
Sep 21 12:45:18.043327 sonic INFO kernel: [94386.904787] device Ethernet192 left promiscuous mode
Sep 21 12:45:18.043375 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_newlink.NOTICE] Update local port Ethernet196 state down
Sep 21 12:45:18.043375 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_deladdr.NOTICE] l3_proto 0, ifname Ethernet196 index 1692 is_vrf 0 address fe80::526b:4bff:fe9b:82c0
Sep 21 12:45:18.043375 sonic NOTICE iccpd#mclagsyncd: :- setPortMacLearnMode: set port mac learn mode, port: Ethernet196, learn-mode: hardware
Sep 21 12:45:18.043375 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_newlink.NOTICE] Update local port PortChannel2001 state down
Sep 21 12:45:18.043375 sonic NOTICE iccpd#mclagsyncd: :- setFdbEntry: del fdb entry from ASIC_DB:key =Vlan10:04:3f:72:2f:38:00
Sep 21 12:45:18.043375 sonic NOTICE iccpd#mclagsyncd: :- setFdbEntry: del fdb entry from ASIC_DB:key =Vlan100:04:3f:72:2f:38:00
Sep 21 12:45:18.043375 sonic NOTICE iccpd#mclagsyncd: :- setFdbEntry: del fdb entry from ASIC_DB:key =Vlan100:64:9d:99:17:cb:2c
Sep 21 12:45:18.048576 sonic INFO kernel: [94386.910831] PortChannel2001: Port device Ethernet192 removed
Sep 21 12:45:18.048626 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_newlink.NOTICE] Update local port Ethernet192 state down
Sep 21 12:45:18.048626 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_deladdr.NOTICE] l3_proto 0, ifname Ethernet192 index 1691 is_vrf 0 address fe80::526b:4bff:fe9b:82c0
Sep 21 12:45:18.048626 sonic NOTICE iccpd#mclagsyncd: :- setPortMacLearnMode: set port mac learn mode, port: Ethernet192, learn-mode: hardware
Sep 21 12:45:18.087773 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fe80::/64 :: eth0
Sep 21 12:45:18.087773 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: 0.0.0.0/0 192.168.0.1 eth0
Sep 21 12:45:18.087773 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: ::/0 fe80::21b:21ff:febe:2f0 eth0
Sep 21 12:45:18.087773 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fd00::/80 :: docker0
Sep 21 12:45:18.087773 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: 0.0.0.0/0 192.168.0.1 eth0
Sep 21 12:45:18.087773 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: ::/0 fe80::21b:21ff:febe:2f0 eth0
Sep 21 12:45:18.087773 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fd00::/80 :: docker0
Sep 21 12:45:18.087773 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fe80::/64 :: eth0
Sep 21 12:45:18.087773 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: 0.0.0.0/0 192.168.0.1 eth0
Sep 21 12:45:18.087773 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: ::/0 fe80::21b:21ff:febe:2f0 eth0
Sep 21 12:45:18.087773 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fd00::/80 :: docker0
Sep 21 12:45:18.094756 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_deladdr.NOTICE] l3_proto 0, ifname PortChannel184 index 1601 is_vrf 0 address fe80::63f:72ff:fe2f:3800
Sep 21 12:45:18.103547 sonic INFO kernel: [94386.957158] Bridge: port 3(PortChannel184) entered disabled state
Sep 21 12:45:18.103576 sonic INFO kernel: [94386.958188] device PortChannel184 left promiscuous mode
Sep 21 12:45:18.103580 sonic INFO kernel: [94386.958210] Bridge: port 3(PortChannel184) entered disabled state
Sep 21 12:45:18.103623 sonic WARNING iccpd#iccpd: [local_if_destroy.WARN] Destroy interface PortChannel184, 1601
Sep 21 12:45:18.103623 sonic NOTICE iccpd#iccpd: [local_if_del_all_vlan.NOTICE] Remove all VLANs from PortChannel184
Sep 21 12:45:18.103623 sonic NOTICE iccpd#mclagsyncd: :- mclagsyncdSetTrafficDisable: Set traffic enable for PortChannel184
Sep 21 12:45:18.126455 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_deladdr.NOTICE] l3_proto 0, ifname PortChannel2001 index 1608 is_vrf 0 address fe80::526b:4bff:fe9b:82c0
Sep 21 12:45:18.128311 sonic INFO kernel: [94386.989136] Bridge: port 4(PortChannel2001) entered disabled state
Sep 21 12:45:18.128338 sonic INFO kernel: [94386.989724] device PortChannel2001 left promiscuous mode
Sep 21 12:45:18.128340 sonic INFO kernel: [94386.989745] Bridge: port 4(PortChannel2001) entered disabled state
Sep 21 12:45:18.128566 sonic WARNING iccpd#iccpd: [local_if_destroy.WARN] Destroy interface PortChannel2001, 1608
Sep 21 12:45:18.128651 sonic NOTICE iccpd#iccpd: [ICCP_FSM.NOTICE] scheduler session disconnect handler
Sep 21 12:45:18.128853 sonic NOTICE iccpd#iccpd: [ICCP_FSM.NOTICE] CSM socket 17 close, location 1
Sep 21 12:45:18.128889 sonic NOTICE iccpd#iccpd: [ICCP_FSM.NOTICE] ICCP session down: warm reboot no, role standby, sync_state MLACP_STATE_EXCHANGE
Sep 21 12:45:18.129269 sonic NOTICE iccpd#iccpd: [update_vlan_if_mac_on_iccp_up.NOTICE]  lif name PortChannel2001, up 0
Sep 21 12:45:18.129353 sonic NOTICE iccpd#iccpd: [recover_vlan_if_mac_on_standby.NOTICE]  remote system_id not initialised.
Sep 21 12:45:18.129565 sonic NOTICE iccpd#iccpd: [recover_vlan_if_mac_on_standby.NOTICE]  remote system_id not initialised.
Sep 21 12:45:18.129565 sonic NOTICE iccpd#iccpd: [ICCP_FDB.NOTICE] mlacp_mac_msg_queue_reinit clear mac_msg_list pointers in existing MAC entries
Sep 21 12:45:18.129749 sonic NOTICE iccpd#iccpd: [local_if_del_all_vlan.NOTICE] Remove all VLANs from PortChannel2001
Sep 21 12:45:18.130065 sonic NOTICE iccpd#mclagsyncd: :- setFdbEntry: del fdb entry from ASIC_DB:key =Vlan10:04:3f:72:2f:38:00
Sep 21 12:45:18.130324 sonic NOTICE iccpd#mclagsyncd: :- setFdbEntry: del fdb entry from ASIC_DB:key =Vlan100:04:3f:72:2f:38:00
Sep 21 12:45:18.130548 sonic NOTICE iccpd#mclagsyncd: :- setFdbEntry: del fdb entry from ASIC_DB:key =Vlan100:64:9d:99:17:cb:2c
Sep 21 12:45:18.130799 sonic NOTICE iccpd#mclagsyncd: :- mclagsyncdSetIccpState: Set mlag 1 ICCP state to down
Sep 21 12:45:18.131063 sonic NOTICE iccpd#mclagsyncd: :- mclagsyncdSetSystemId: Set mlag 1 system mac to 50:6b:4b:9b:82:c0
Sep 21 12:45:18.131277 sonic NOTICE iccpd#mclagsyncd: :- mclagsyncdDelRemoteIfInfo: Delete mlag 1, remote interface PortChannel176
Sep 21 12:45:18.131492 sonic NOTICE iccpd#mclagsyncd: :- mclagsyncdDelRemoteIfInfo: Delete mlag 1, remote interface PortChannel184
Sep 21 12:45:18.163669 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: 0.0.0.0/0 192.168.0.1 eth0
Sep 21 12:45:18.163669 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: ::/0 fe80::21b:21ff:febe:2f0 eth0
Sep 21 12:45:18.163669 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fd00::/80 :: docker0
Sep 21 12:45:18.167363 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: 0.0.0.0/0 192.168.0.1 eth0
Sep 21 12:45:18.177880 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: ::/0 fe80::21b:21ff:febe:2f0 eth0
Sep 21 12:45:18.177880 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fd00::/80 :: docker0
Sep 21 12:45:18.975330 sonic INFO teamd#supervisord 2023-09-21 12:45:18,973 INFO reaped unknown pid 28 (exit status 0)
Sep 21 12:45:18.975330 sonic INFO teamd#supervisord 2023-09-21 12:45:18,974 INFO reaped unknown pid 36 (exit status 0)
Sep 21 12:45:18.975330 sonic INFO teamd#supervisord 2023-09-21 12:45:18,974 INFO reaped unknown pid 44 (exit status 0)
Sep 21 12:45:18.986955 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_newlink.NOTICE] Update local port Vlan10 state down
Sep 21 12:45:18.988649 sonic NOTICE iccpd#iccpd: [iccp_event_handler_obj_input_newlink.NOTICE] Update local port Vlan100 state down
Sep 21 12:45:18.997110 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fe80::/64 :: eth0
Sep 21 12:45:18.997179 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: 0.0.0.0/0 192.168.0.1 eth0
Sep 21 12:45:18.997397 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: ::/0 fe80::21b:21ff:febe:2f0 eth0
Sep 21 12:45:18.997857 sonic NOTICE bgp#fpmsyncd: :- onRouteMsg: RouteTable del msg for route with only one nh on eth0/docker0: fd00::/80 :: docker0
Sep 21 12:45:19.013241 sonic NOTICE teamd#teammgrd: :- cleanTeamProcesses: Waiting for port channel PortChannel184 pid 36 to stop...
Sep 21 12:45:19.020359 sonic NOTICE teamd#teammgrd: :- cleanTeamProcesses: Waiting for port channel PortChannel176 pid 28 to stop...
Sep 21 12:45:19.020359 sonic NOTICE teamd#teammgrd: :- cleanTeamProcesses: LAGs cleanup is done
Sep 21 12:45:19.020359 sonic NOTICE teamd#teammgrd: :- main: Exiting
Sep 21 12:45:19.221554 sonic INFO teamd#supervisord 2023-09-21 12:45:19,212 INFO stopped: teammgrd (exit status 0)
Sep 21 12:45:20.355124 sonic INFO containerd[391]: time="2023-09-21T12:45:20.353731751+08:00" level=info msg="shim disconnected" id=27273f07b770a3f406ba4c442239b982fff17cd054d2d9aee8b04310c2249fa7
Sep 21 12:45:20.355256 sonic INFO containerd[391]: time="2023-09-21T12:45:20.353822579+08:00" level=warning msg="cleaning up after shim disconnected" id=27273f07b770a3f406ba4c442239b982fff17cd054d2d9aee8b04310c2249fa7 namespace=moby
Sep 21 12:45:20.355337 sonic INFO containerd[391]: time="2023-09-21T12:45:20.353849604+08:00" level=info msg="cleaning up dead shim"
Sep 21 12:45:20.356658 sonic INFO dockerd[589]: time="2023-09-21T12:45:20.355608603+08:00" level=info msg="ignoring event" container=27273f07b770a3f406ba4c442239b982fff17cd054d2d9aee8b04310c2249fa7 module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
Sep 21 12:45:20.395449 sonic INFO containerd[391]: time="2023-09-21T12:45:20.395298825+08:00" level=warning msg="cleanup warnings time=\"2023-09-21T12:45:20+08:00\" level=info msg=\"starting signal loop\" namespace=moby pid=1181807 runtime=io.containerd.runc.v2\n"
Sep 21 12:45:20.453520 sonic INFO systemd[1]: var-lib-docker-overlay2-1dc204245c2f4eb4429a5504ff2ef3b996e1596a2e1e3c0c302ea37f9689c9de-merged.mount: Succeeded.
Sep 21 12:45:20.515506 sonic INFO container: docker cmd: wait for teamd
Sep 21 12:45:20.528427 sonic INFO container: docker cmd: stop for teamd
Sep 21 12:45:20.532899 sonic DEBUG container: container_stop: END
Sep 21 12:45:20.693741 sonic NOTICE admin: Stopped teamd service...
Sep 21 12:45:20.706308 sonic INFO systemd[1]: teamd.service: Succeeded.
Sep 21 12:45:20.706454 sonic INFO systemd[1]: Stopped TEAMD container.
Sep 21 12:45:20.711028 sonic NOTICE rsyslog_plugin: :- publish: EVENT_PUBLISHED: {"sonic-events-host:event-stopped-ctr":{"ctr_name":"TEAMD","timestamp":"2023-09-21T12:45:20.706783Z"}}
Sep 21 12:45:20.731952 sonic INFO systemd[1]: Stopping Router advertiser container...
Sep 21 12:45:20.752767 sonic NOTICE admin: Stopping radv service...
Sep 21 12:45:20.758480 sonic NOTICE healthd: System is not ready - one or more services are not up
Sep 21 12:45:20.858399 sonic NOTICE admin: DEVICE_SUBTYPE: , CONFIG_KNOB:
Sep 21 12:45:20.870442 sonic NOTICE admin: Warm boot flag: radv false.
Sep 21 12:45:20.882539 sonic NOTICE admin: Fast boot flag: radv false.
Sep 21 12:45:21.373791 sonic INFO systemd[1]: run-docker-runtime\x2drunc-moby-b08e3c24fd0869e6085e9476afff40e4ae88f12512be34edacf1be374a081168-runc.YSFl4f.mount: Succeeded.
Sep 21 12:45:21.859681 sonic DEBUG container: container_stop: BEGIN
Sep 21 12:45:21.863155 sonic DEBUG container: read_data: config:True feature:radv fields:[('set_owner', 'local'), ('no_fallback_to_local', False), ('state', 'disabled')] val:['local', False, 'enabled']
Sep 21 12:45:21.865428 sonic DEBUG container: read_data: config:False feature:radv fields:[('current_owner', 'none'), ('remote_state', 'none'), ('container_id', '')] val:['none', 'none', '']
Sep 21 12:45:21.868155 sonic DEBUG container: container_stop: radv: set_owner:local current_owner:none remote_state:none docker_id:radv
Sep 21 12:45:22.265046 sonic INFO radv#supervisord 2023-09-21 12:45:22,262 WARN received SIGTERM indicating exit request
Sep 21 12:45:22.265046 sonic INFO radv#supervisord 2023-09-21 12:45:22,262 INFO waiting for supervisor-proc-exit-script, rsyslogd, containercfgd to die
Sep 21 12:45:23.290400 sonic INFO radv#supervisord 2023-09-21 12:45:23,289 INFO stopped: containercfgd (exit status 143)
Sep 21 12:45:24.385870 sonic INFO containerd[391]: time="2023-09-21T12:45:24.385146831+08:00" level=info msg="shim disconnected" id=da036c5ecf286d7bf932731bd657f618ec8fb6193939179ef7bf5ea90179babd
Sep 21 12:45:24.385993 sonic INFO containerd[391]: time="2023-09-21T12:45:24.385241765+08:00" level=warning msg="cleaning up after shim disconnected" id=da036c5ecf286d7bf932731bd657f618ec8fb6193939179ef7bf5ea90179babd namespace=moby
Sep 21 12:45:24.386096 sonic INFO containerd[391]: time="2023-09-21T12:45:24.385268266+08:00" level=info msg="cleaning up dead shim"
Sep 21 12:45:24.386770 sonic INFO dockerd[589]: time="2023-09-21T12:45:24.385724214+08:00" level=info msg="ignoring event" container=da036c5ecf286d7bf932731bd657f618ec8fb6193939179ef7bf5ea90179babd module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
Sep 21 12:45:24.404119 sonic INFO containerd[391]: time="2023-09-21T12:45:24.403953665+08:00" level=warning msg="cleanup warnings time=\"2023-09-21T12:45:24+08:00\" level=info msg=\"starting signal loop\" namespace=moby pid=1181995 runtime=io.containerd.runc.v2\n"
Sep 21 12:45:24.453500 sonic INFO systemd[1]: var-lib-docker-overlay2-d999e1bac7d4a8364665ceffcbf4da5b3161d5b25c43b2aee052f111bef78f78-merged.mount: Succeeded.
Sep 21 12:45:24.501561 sonic INFO container: docker cmd: wait for radv
Sep 21 12:45:24.506965 sonic INFO container: docker cmd: stop for radv
Sep 21 12:45:24.508845 sonic DEBUG container: container_stop: END
Sep 21 12:45:24.607124 sonic NOTICE admin: Stopped radv service...
Sep 21 12:45:24.638623 sonic INFO systemd[1]: radv.service: Succeeded.
Sep 21 12:45:24.638777 sonic INFO systemd[1]: Stopped Router advertiser container.
Sep 21 12:45:24.642218 sonic NOTICE rsyslog_plugin: :- publish: EVENT_PUBLISHED: {"sonic-events-host:event-stopped-ctr":{"ctr_name":"Router advertiser","timestamp":"2023-09-21T12:45:24.639696Z"}}
Sep 21 12:45:24.656412 sonic INFO systemd[1]: Stopping BGP container...
Sep 21 12:45:24.677137 sonic NOTICE admin: Stopping bgp service...
Sep 21 12:45:24.744531 sonic NOTICE admin: Warm boot flag: bgp false.
Sep 21 12:45:24.755566 sonic NOTICE admin: Fast boot flag: bgp false.
Sep 21 12:45:25.305180 sonic INFO dbus-daemon[368]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.24' (uid=0 pid=1182091 comm="systemd-analyze plot ")

I notice there are some issue related to crash like #2332. I think this behavior happen randomly regardless if MAC address is static or dynamic.

I also attach dump log file too.

sai_sdk_dump_09_21_2023_04_47_AM.tar.gz

I faced a similar issue, and after some investigation, I discovered these changes that resolved the issue.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@ccy @naaysayer