From e2888172c6ad863f2b47dea0432ad0ee7cc1f5c9 Mon Sep 17 00:00:00 2001 From: Mihir Patel Date: Wed, 18 Sep 2024 21:52:30 +0000 Subject: [PATCH 1/4] [xcvrd] Add logs to improve debugging in xcvrd Signed-off-by: Mihir Patel --- sonic-xcvrd/xcvrd/xcvrd.py | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/sonic-xcvrd/xcvrd/xcvrd.py b/sonic-xcvrd/xcvrd/xcvrd.py index c8e355cb3..3f19f1646 100644 --- a/sonic-xcvrd/xcvrd/xcvrd.py +++ b/sonic-xcvrd/xcvrd/xcvrd.py @@ -440,6 +440,7 @@ def post_port_sfp_info_to_db(logical_port_name, port_mapping, table, transceiver break if not _wrapper_get_presence(physical_port): + helper_logger.log_warning("Transceiver not present in port {}".format(logical_port_name)) continue port_name = get_physical_port_name(logical_port_name, ganged_member_num, ganged_port) @@ -1379,6 +1380,7 @@ def task_worker(self): # Skip if it's not a CMIS module type = api.get_module_type_abbreviation() if (type is None) or (type not in self.CMIS_MODULE_TYPES): + self.log_notice("{}: skipping CMIS state machine for non-CMIS module with type {}".format(lport, type)) self.update_port_transceiver_status_table_sw_cmis_state(lport, CMIS_STATE_READY) continue @@ -1413,9 +1415,9 @@ def task_worker(self): self.update_port_transceiver_status_table_sw_cmis_state(lport, CMIS_STATE_FAILED) continue - self.log_notice("{}: {}G, lanemask=0x{:x}, state={}, appl {} host_lane_count {} " - "retries={}".format(lport, int(speed/1000), host_lanes_mask, - state, appl, host_lane_count, retries)) + self.log_notice("{}: {}G, lanemask=0x{:x}, CMIS state={}, Module state={}, DP state={}, appl {} host_lane_count {} " + "retries={}".format(lport, int(speed/1000), host_lanes_mask, state, + api.get_module_state(), api.get_datapath_state(), appl, host_lane_count, retries)) if retries > self.CMIS_MAX_RETRIES: self.log_error("{}: FAILED".format(lport)) self.update_port_transceiver_status_table_sw_cmis_state(lport, CMIS_STATE_FAILED) From 16251cd586bde45f9ebe700e9406834e3da3e279 Mon Sep 17 00:00:00 2001 From: Mihir Patel Date: Thu, 19 Sep 2024 00:10:06 +0000 Subject: [PATCH 2/4] Fixed unit-test failure --- sonic-xcvrd/tests/test_xcvrd.py | 70 +++++++++++++++++++++++++++++++++ 1 file changed, 70 insertions(+) diff --git a/sonic-xcvrd/tests/test_xcvrd.py b/sonic-xcvrd/tests/test_xcvrd.py index 58d8ca3b6..8ea8da717 100644 --- a/sonic-xcvrd/tests/test_xcvrd.py +++ b/sonic-xcvrd/tests/test_xcvrd.py @@ -1867,6 +1867,56 @@ def test_CmisManagerTask_task_worker(self, mock_chassis, mock_get_status_tbl): 'DP7State': 'DataPathDeactivated', 'DP8State': 'DataPathDeactivated' }, + { + 'DP1State': 'DataPathDeactivated', + 'DP2State': 'DataPathDeactivated', + 'DP3State': 'DataPathDeactivated', + 'DP4State': 'DataPathDeactivated', + 'DP5State': 'DataPathDeactivated', + 'DP6State': 'DataPathDeactivated', + 'DP7State': 'DataPathDeactivated', + 'DP8State': 'DataPathDeactivated' + }, + { + 'DP1State': 'DataPathDeactivated', + 'DP2State': 'DataPathDeactivated', + 'DP3State': 'DataPathDeactivated', + 'DP4State': 'DataPathDeactivated', + 'DP5State': 'DataPathDeactivated', + 'DP6State': 'DataPathDeactivated', + 'DP7State': 'DataPathDeactivated', + 'DP8State': 'DataPathDeactivated' + }, + { + 'DP1State': 'DataPathDeactivated', + 'DP2State': 'DataPathDeactivated', + 'DP3State': 'DataPathDeactivated', + 'DP4State': 'DataPathDeactivated', + 'DP5State': 'DataPathDeactivated', + 'DP6State': 'DataPathDeactivated', + 'DP7State': 'DataPathDeactivated', + 'DP8State': 'DataPathDeactivated' + }, + { + 'DP1State': 'DataPathInitialized', + 'DP2State': 'DataPathInitialized', + 'DP3State': 'DataPathInitialized', + 'DP4State': 'DataPathInitialized', + 'DP5State': 'DataPathInitialized', + 'DP6State': 'DataPathInitialized', + 'DP7State': 'DataPathInitialized', + 'DP8State': 'DataPathInitialized' + }, + { + 'DP1State': 'DataPathInitialized', + 'DP2State': 'DataPathInitialized', + 'DP3State': 'DataPathInitialized', + 'DP4State': 'DataPathInitialized', + 'DP5State': 'DataPathInitialized', + 'DP6State': 'DataPathInitialized', + 'DP7State': 'DataPathInitialized', + 'DP8State': 'DataPathInitialized' + }, { 'DP1State': 'DataPathInitialized', 'DP2State': 'DataPathInitialized', @@ -1877,6 +1927,26 @@ def test_CmisManagerTask_task_worker(self, mock_chassis, mock_get_status_tbl): 'DP7State': 'DataPathInitialized', 'DP8State': 'DataPathInitialized' }, + { + 'DP1State': 'DataPathInitialized', + 'DP2State': 'DataPathInitialized', + 'DP3State': 'DataPathInitialized', + 'DP4State': 'DataPathInitialized', + 'DP5State': 'DataPathInitialized', + 'DP6State': 'DataPathInitialized', + 'DP7State': 'DataPathInitialized', + 'DP8State': 'DataPathInitialized' + }, + { + 'DP1State': 'DataPathActivated', + 'DP2State': 'DataPathActivated', + 'DP3State': 'DataPathActivated', + 'DP4State': 'DataPathActivated', + 'DP5State': 'DataPathActivated', + 'DP6State': 'DataPathActivated', + 'DP7State': 'DataPathActivated', + 'DP8State': 'DataPathActivated' + }, { 'DP1State': 'DataPathActivated', 'DP2State': 'DataPathActivated', From 70ee9aca269d19532514831537632b6669061fd4 Mon Sep 17 00:00:00 2001 From: Mihir Patel Date: Thu, 19 Sep 2024 05:48:51 +0000 Subject: [PATCH 3/4] Improved code coverage --- sonic-xcvrd/tests/test_xcvrd.py | 19 +++++++++++++++++++ 1 file changed, 19 insertions(+) diff --git a/sonic-xcvrd/tests/test_xcvrd.py b/sonic-xcvrd/tests/test_xcvrd.py index 8ea8da717..3141cc749 100644 --- a/sonic-xcvrd/tests/test_xcvrd.py +++ b/sonic-xcvrd/tests/test_xcvrd.py @@ -225,6 +225,14 @@ def test_CmisManagerTask_get_xcvr_api_exception(self, mock_platform_chassis, moc task.task_worker() assert get_cmis_state_from_state_db('Ethernet0', task.xcvr_table_helper.get_status_tbl(task.port_mapping.get_asic_id_for_logical_port('Ethernet0'))) == CMIS_STATE_READY + # Case 2.5: get_module_type_abbreviation() returns unsupported module type. In this case, CMIS SM should transition to READY state + mock_xcvr_api.is_flat_memory = MagicMock(return_value=False) + mock_xcvr_api.get_module_type_abbreviation = MagicMock(return_value='SFP') + task.task_stopping_event.is_set = MagicMock(side_effect=[False, False, True]) + task.on_port_update_event(port_change_event) + task.task_worker() + assert get_cmis_state_from_state_db('Ethernet0', task.xcvr_table_helper.get_status_tbl(task.port_mapping.get_asic_id_for_logical_port('Ethernet0'))) == CMIS_STATE_READY + # Case 3: get_cmis_application_desired() raises an exception mock_xcvr_api.is_flat_memory = MagicMock(return_value=False) mock_xcvr_api.is_coherent_module = MagicMock(return_value=False) @@ -543,6 +551,17 @@ def test_post_port_sfp_info_to_db(self): transceiver_dict = {} post_port_sfp_info_to_db(logical_port_name, port_mapping, dom_tbl, transceiver_dict, stop_event) + @patch('xcvrd.xcvrd_utilities.port_event_helper.PortMapping.logical_port_name_to_physical_port_list', MagicMock(return_value=[0])) + @patch('xcvrd.xcvrd._wrapper_get_presence', MagicMock(return_value=False)) + def test_post_port_sfp_info_to_db_with_sfp_not_present(self): + logical_port_name = "Ethernet0" + port_mapping = PortMapping() + stop_event = threading.Event() + intf_tbl = Table("STATE_DB", TRANSCEIVER_INFO_TABLE) + transceiver_dict = {} + post_port_sfp_info_to_db(logical_port_name, port_mapping, intf_tbl , transceiver_dict, stop_event) + assert xcvrd._wrapper_get_presence.call_count == 1 + @patch('xcvrd.xcvrd_utilities.port_event_helper.PortMapping.logical_port_name_to_physical_port_list', MagicMock(return_value=[0])) @patch('xcvrd.xcvrd.platform_sfputil', MagicMock(return_value=[0])) @patch('xcvrd.xcvrd._wrapper_get_presence', MagicMock(return_value=True)) From f17cb9cf252feb1ca19d130f63dd1e74c00641ea Mon Sep 17 00:00:00 2001 From: Mihir Patel Date: Thu, 19 Sep 2024 16:04:51 +0000 Subject: [PATCH 4/4] Changed warning to notice --- sonic-xcvrd/xcvrd/xcvrd.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/sonic-xcvrd/xcvrd/xcvrd.py b/sonic-xcvrd/xcvrd/xcvrd.py index 3f19f1646..f07da1572 100644 --- a/sonic-xcvrd/xcvrd/xcvrd.py +++ b/sonic-xcvrd/xcvrd/xcvrd.py @@ -440,7 +440,7 @@ def post_port_sfp_info_to_db(logical_port_name, port_mapping, table, transceiver break if not _wrapper_get_presence(physical_port): - helper_logger.log_warning("Transceiver not present in port {}".format(logical_port_name)) + helper_logger.log_notice("Transceiver not present in port {}".format(logical_port_name)) continue port_name = get_physical_port_name(logical_port_name, ganged_member_num, ganged_port)