Closed ZhaohuiS closed 1 year ago
After checking log file test_configurable_drop_counters-0606-dx010-7-1.log
, analysis:
Test steps:
Steps:
Analysis:
docker exec -i swss swssconfig /fdb_set.json
FDB add successfully. FDB Add-[Ok]: MAC:72-06-00-01-00-41 vfi:0x3e8
Jun 6 08:10:16.791549 str2-dx010-acs-7 INFO python[861809]: ansible-command Invoked with _raw_params=docker exec -i swss swssconfig /fdb.json warn=True _uses_shell=False stdin_add_newline=True strip_empty_ends=True argv=None chdir=None executable=None creates=None removes=None stdin=None
Jun 6 08:10:16.972960 str2-dx010-acs-7 NOTICE swss#swssconfig: :- main: Loading config from JSON file:/fdb.json...
Jun 6 08:10:16.988247 str2-dx010-acs-7 INFO syncd#syncd: [none] SAI_API_FDB:brcm_sai_set_fdb_entry_attribute:1130 FDB MAC:72-06-00-01-00-41 port_tid:0x1 tgid:0 port_type:Port vlan_id:1000 vid:0x3e8
Jun 6 08:10:16.988247 str2-dx010-acs-7 INFO syncd#syncd: [none] SAI_API_FDB:brcm_sai_set_fdb_entry_attribute:1140 Setting Type SAI_FDB_ENTRY_TYPE_STATIC:
Jun 6 08:10:16.988247 str2-dx010-acs-7 INFO syncd#syncd: [none] SAI_API_FDB:brcm_sai_bcm_l2_addr_add:154 FDB Add-[Ok]: MAC:72-06-00-01-00-41 vfi:0x3e8
Jun 6 08:10:16.992527 str2-dx010-acs-7 INFO syncd#syncd: [none] SAI_API_FDB:brcm_sai_set_fdb_entry_attribute:1130 FDB MAC:72-06-00-01-00-41 port_tid:0x1 tgid:0 port_type:Port vlan_id:1000 vid:0x3e8
Jun 6 08:10:16.992818 str2-dx010-acs-7 INFO syncd#syncd: [none] SAI_API_FDB:brcm_sai_set_fdb_entry_attribute:1251 L2 port: 1
Jun 6 08:10:16.993032 str2-dx010-acs-7 INFO syncd#syncd: [none] SAI_API_FDB:brcm_sai_bcm_l2_addr_add:154 FDB Add-[Ok]: MAC:72-06-00-01-00-41 vfi:0x3e8
fdbEvent: delete (0) for mac 72-06-00-01-00-41 vid:0x3e8
Jun 6 08:10:32.599375 str2-dx010-acs-7 INFO syncd#syncd: [none] SAI_API_PORT:_brcm_sai_link_event_cb:1150 Port 1 link down event cause: LOCAL
Jun 6 08:10:32.604374 str2-dx010-acs-7 NOTICE swss#orchagent: :- doTask: Get port state change notification id:1000000000002 status:2
Jun 6 08:10:32.604886 str2-dx010-acs-7 NOTICE swss#orchagent: :- updatePortOperStatus: Port Ethernet80 oper state set from up to down
Jun 6 08:10:32.610286 str2-dx010-acs-7 NOTICE swss#orchagent: :- setHostIntfsOperStatus: Set operation status DOWN to host interface Ethernet80
Jun 6 08:10:32.611092 str2-dx010-acs-7 NOTICE swss#portsyncd: :- onMsg: nlmsg type:16 key:Ethernet80 admin:1 oper:0 addr:00:e0:ec:c2:af:7a ifindex:95 master:91
Jun 6 08:10:32.611353 str2-dx010-acs-7 NOTICE swss#orchagent: :- flushFdbEntries: flush key: SAI_OBJECT_TYPE_FDB_FLUSH:oid:0x21000000000000, fields: 1
Jun 6 08:10:32.611550 str2-dx010-acs-7 NOTICE swss#orchagent: :- recordFlushFdbEntries: flush key: SAI_OBJECT_TYPE_FDB_FLUSH:oid:0x21000000000000, fields: 1
Jun 6 08:10:32.612827 str2-dx010-acs-7 NOTICE swss#portsyncd: :- onMsg: Publish Ethernet80(ok:down) to state db
Jun 6 08:10:32.613094 str2-dx010-acs-7 NOTICE swss#portsyncd: :- onMsg: nlmsg type:16 key:Ethernet80 admin:1 oper:0 addr:00:e0:ec:c2:af:7a ifindex:95 master:91
Jun 6 08:10:32.613379 str2-dx010-acs-7 NOTICE swss#portsyncd: :- onMsg: Publish Ethernet80(ok:down) to state db
Jun 6 08:10:32.613488 str2-dx010-acs-7 INFO kernel: [33556.638716] Bridge: port 20(Ethernet80) entered disabled state
Jun 6 08:10:32.615512 str2-dx010-acs-7 NOTICE syncd#syncd: :- processFdbFlush: fdb flush succeeded, updating redis database
Jun 6 08:10:32.615512 str2-dx010-acs-7 NOTICE syncd#syncd: :- processFlushEvent: received a flush port fdb event, portVid = oid:0x3a0000000005ea, bvId = oid:0x0
Jun 6 08:10:32.615512 str2-dx010-acs-7 NOTICE syncd#syncd: :- processFlushEvent: pattern ASIC_STATE:SAI_OBJECT_TYPE_FDB_ENTRY:*, portStr oid:0x3a0000000005ea
Jun 6 08:10:32.617644 str2-dx010-acs-7 INFO syncd#syncd: [none] SAI_API_FDB:_brcm_sai_fdb_event_cb:216 fdbEvent: delete (0) for mac 72-06-00-01-00-41 vid:0x3e8, port:0x1 lagid:0x0 flags:0x10c60 flags2:0x0 lag:false station flags 0x0
SAI_FDB_ENTRY_TYPE_DYNAMIC
FDB Add-[Ok]: MAC:72-06-00-01-00-41 vfi:0x3e8
Jun 6 08:10:32.650856 str2-dx010-acs-7 NOTICE swss#orchagent: :- meta_sai_on_fdb_flush_event_consolidated: processing consolidated fdb flush event of type: SAI_FDB_ENTRY_TYPE_DYNAMIC
Jun 6 08:10:32.655723 str2-dx010-acs-7 NOTICE swss#orchagent: :- meta_sai_on_fdb_flush_event_consolidated: fdb flush took 0.004869 sec
Jun 6 08:10:32.658985 str2-dx010-acs-7 INFO syncd#syncd: [none] SAI_API_FDB:brcm_sai_bcm_l2_addr_add:154 FDB Add-[Ok]: MAC:72-06-00-01-00-41 vfi:0x3e8
Jun 6 08:10:32.659099 str2-dx010-acs-7 INFO syncd#syncd: [none] SAI_API_NEIGHBOR:brcm_sai_xgs_common_neighbor_mac_db_update:114 Process fdb nbr update for [1000].[72:06:00:01:00:41]. add 0, dir 5
Jun 6 08:10:32.659175 str2-dx010-acs-7 INFO syncd#syncd: [none] SAI_API_NEIGHBOR:brcm_sai_xgs_common_neighbor_mac_db_update:114 Process fdb nbr update for [1000].[72:06:00:01:00:41]. add 1, dir 6
Jun 6 08:10:32.659252 str2-dx010-acs-7 INFO syncd#syncd: [none] SAI_API_NEIGHBOR:brcm_sai_xgs_common_neighbor_mac_db_update:360 brcm_sai_mptnl_notify_nhop_event success: 0, add 1 dir 6
Jun 6 08:10:32.659326 str2-dx010-acs-7 INFO syncd#syncd: [none] SAI_API_NEIGHBOR:brcm_sai_xgs_common_neighbor_mac_db_update:364 Updated egress object: 100036 flags : 0
Jun 6 08:10:32.659400 str2-dx010-acs-7 INFO syncd#syncd: [none] SAI_API_FDB:brcm_sai_create_fdb_entry:920 FDB Create: MAC:72-06-00-01-00-41 port:0x1 tid:0x0 port_type:Port vid:0x3e8
fdbEvent: add (1) for mac DE-AD-BE-EF-12-34 vid:0x3e8
Jun 6 08:10:47.132892 str2-dx010-acs-7 INFO syncd#syncd: [none] SAI_API_FDB:_brcm_sai_fdb_event_cb:216 fdbEvent: add (1) for mac DE-AD-BE-EF-12-34 vid:0x3e8, port:0x3e lagid:0x0 flags:0x10440 flags2:0x0 lag:false station flags 0x0
Jun 6 08:10:47.132987 str2-dx010-acs-7 INFO syncd#syncd: [none] SAI_API_NEIGHBOR:brcm_sai_xgs_common_neighbor_mac_db_update:105 Mac entry not found - skip nbr processing. add 1, dir 4
sonic-clear fdb
, delete fdb for both 72-06-00-01-00-41 and DE-AD-BE-EF-12-34. fdbEvent: delete (0) for mac 72-06-00-01-00-41
fdbEvent: delete (0) for mac DE-AD-BE-EF-12-34
. Err reported. meta_sai_validate_fdb_entry: object key SAI_OBJECT_TYPE_FDB_ENTRY:{"bvid":"oid:0x260000000005c5","mac":"72:06:00:01:00:41","switch_id":"oid:0x21000000000000"} already exists
Jun 6 08:10:57.241109 str2-dx010-acs-7 INFO python[862885]: ansible-command Invoked with _raw_params=sonic-clear fdb all warn=True _uses_shell=False stdin_add_newline=True strip_empty_ends=True argv=None chdir=None executable=None creates=None removes=None stdin=None
Jun 6 08:10:58.341149 str2-dx010-acs-7 NOTICE swss#orchagent: :- flushFdbEntries: flush key: SAI_OBJECT_TYPE_FDB_FLUSH:oid:0x21000000000000, fields: 0
Jun 6 08:10:58.341746 str2-dx010-acs-7 NOTICE swss#orchagent: :- recordFlushFdbEntries: flush key: SAI_OBJECT_TYPE_FDB_FLUSH:oid:0x21000000000000, fields: 0
Jun 6 08:10:58.347394 str2-dx010-acs-7 INFO syncd#syncd: [none] SAI_API_FDB:_brcm_sai_fdb_event_cb:216 fdbEvent: delete (0) for mac 72-06-00-01-00-41 vid:0x3e8, port:0x1 lagid:0x0 flags:0x10020 flags2:0x0 lag:false station flags 0x0
Jun 6 08:10:58.347679 str2-dx010-acs-7 INFO syncd#syncd: [none] SAI_API_NEIGHBOR:brcm_sai_xgs_common_neighbor_mac_db_update:114 Process fdb nbr update for [1000].[72:06:00:01:00:41]. add 0, dir 4
Jun 6 08:10:58.347892 str2-dx010-acs-7 INFO syncd#syncd: [none] SAI_API_NEIGHBOR:brcm_sai_xgs_common_neighbor_mac_db_update:360 brcm_sai_mptnl_notify_nhop_event success: 0, add 0 dir 4
Jun 6 08:10:58.348070 str2-dx010-acs-7 INFO syncd#syncd: [none] SAI_API_NEIGHBOR:brcm_sai_xgs_common_neighbor_mac_db_update:364 Updated egress object: 100036 flags : 100000
Jun 6 08:10:58.356141 str2-dx010-acs-7 INFO syncd#syncd: [none] SAI_API_FDB:_brcm_sai_fdb_event_cb:216 fdbEvent: delete (0) for mac DE-AD-BE-EF-12-34 vid:0x3e8, port:0x3e lagid:0x0 flags:0x10440 flags2:0x0 lag:false station flags 0x0
Jun 6 08:10:58.356386 str2-dx010-acs-7 INFO syncd#syncd: [none] SAI_API_NEIGHBOR:brcm_sai_xgs_common_neighbor_mac_db_update:105 Mac entry not found - skip nbr processing. add 0, dir 4
Jun 6 08:10:58.833311 str2-dx010-acs-7 NOTICE syncd#syncd: :- processFdbFlush: fdb flush succeeded, updating redis database
Jun 6 08:10:58.833820 str2-dx010-acs-7 NOTICE swss#orchagent: :- meta_sai_on_fdb_flush_event_consolidated: processing consolidated fdb flush event of type: SAI_FDB_ENTRY_TYPE_DYNAMIC
Jun 6 08:10:58.838618 str2-dx010-acs-7 NOTICE swss#orchagent: :- meta_sai_on_fdb_flush_event_consolidated: fdb flush took 0.004757 sec
Jun 6 08:10:58.838995 str2-dx010-acs-7 NOTICE syncd#syncd: :- processFlushEvent: received a flush port fdb event, portVid = oid:0x0, bvId = oid:0x0
Jun 6 08:10:58.839254 str2-dx010-acs-7 NOTICE syncd#syncd: :- processFlushEvent: pattern ASIC_STATE:SAI_OBJECT_TYPE_FDB_ENTRY:*, portStr
Jun 6 08:10:58.852598 str2-dx010-acs-7 ERR swss#orchagent: :- meta_sai_validate_fdb_entry: object key SAI_OBJECT_TYPE_FDB_ENTRY:{"bvid":"oid:0x260000000005c5","mac":"72:06:00:01:00:41","switch_id":"oid:0x21000000000000"} already exists
Jun 6 08:10:58.852968 str2-dx010-acs-7 ERR swss#orchagent: :- update: Failed to create FDB 72:06:00:01:00:41 on Ethernet80, rv:-6
Jun 6 08:10:58.853581 str2-dx010-acs-7 WARNING swss#orchagent: :- meta_sai_on_fdb_event_single: object key SAI_OBJECT_TYPE_FDB_ENTRY:{"bvid":"oid:0x260000000005c5","mac":"DE:AD:BE:EF:12:34","switch_id":"oid:0x21000000000000"} doesn't exist but received AGED event
docker exec -i swss swssconfig /fdb_del.json
to cause FdbOrch RemoveFDBEntry: Failed to remove FDB entry. mac=72:06:00:01:00:41
and orchagent crashed.Jun 6 08:11:04.970882 str2-dx010-acs-7 INFO python[863326]: ansible-command Invoked with _raw_params=docker exec -i swss swssconfig /fdb.json warn=True _uses_shell=False stdin_add_newline=True strip_empty_ends=True argv=None chdir=None executable=None creates=None removes=None stdin=None
Jun 6 08:11:05.163633 str2-dx010-acs-7 NOTICE swss#swssconfig: :- main: Loading config from JSON file:/fdb.json...
Jun 6 08:11:05.213229 str2-dx010-acs-7 ERR swss#orchagent: :- meta_sai_validate_fdb_entry: object key SAI_OBJECT_TYPE_FDB_ENTRY:{"bvid":"oid:0x260000000005c5","mac":"72:06:00:01:00:41","switch_id":"oid:0x21000000000000"} doesn't exist
Jun 6 08:11:05.213504 str2-dx010-acs-7 ERR swss#orchagent: :- removeFdbEntry: FdbOrch RemoveFDBEntry: Failed to remove FDB entry. mac=72:06:00:01:00:41, bv_id=0x260000000005c5
Jun 6 08:11:05.213730 str2-dx010-acs-7 ERR swss#orchagent: :- handleSaiRemoveStatus: Encountered failure in remove operation, exiting orchagent, SAI API: SAI_API_FDB, status: SAI_STATUS_INVALID_PARAMETER
Jun 6 08:11:07.610329 str2-dx010-acs-7 INFO swss#supervisord 2022-06-06 08:11:07,609 INFO exited: orchagent (terminated by SIGABRT (core dumped); not expected)
Jun 6 08:11:08.627098 str2-dx010-acs-7 INFO swss#supervisor-proc-exit-listener: Process 'orchagent' exited unexpectedly. Terminating supervisor 'swss'
BRCM will take a look.
FDB flush is removing static mac as well. Need to change flush call to remove only dynamic mac. Will make the change and create PR for review.
PR created for the fix: https://github.com/Azure/sonic-swss/pull/2332
Fixed in this PR https://github.com/sonic-net/sonic-swss/pull/2332.
Description
orchagent crashed when trying to delete fdb static entry with swssconfig, the fdb static entry was added with swssconfig minutes ago.
Steps to reproduce the issue:
tests/drop_counters/test_configurable_drop_counters.py
in sonic-mgmt repo.docker exec -i swss swssconfig /fdb_set_config.json
sonic-clear fdb all
sonic-clear arp
docker exec -i swss swssconfig /fdb_del_config.json
Describe the results you received:
Error log:
The output of
docker ps
:Describe the results you expected:
orchagent should not crash.
Output of
show version
:Output of
show techsupport
:show_tech.log
Additional information you deem important (e.g. issue happens only occasionally):
orchagent.1654503065.105.core.gz
fdb_set_config.txt
fdb_del_config.txt test_configurable_drop_counters-0606-dx010-7-1.log