From 80ebb3ff6ab75f495e16f0833b60682b2fc7fa9d Mon Sep 17 00:00:00 2001 From: "Richard.Yu" Date: Wed, 16 Nov 2022 11:21:36 +0800 Subject: [PATCH] [SAI-PTF] add invocation logger (#1651) * add invocation logger Signed-off-by: richardyu-ms * reformat code Signed-off-by: richardyu-ms Signed-off-by: richardyu-ms Co-authored-by: richardyu --- meta/gensairpc.pl | 7 ++- meta/rpc/README.md | 3 +- meta/templates/sai_adapter.py.tt | 3 + meta/templates/sai_adapter_utils.tt | 37 ++++++++++++ ptf/LogConfig.py | 45 ++++++++++++++ ptf/sai_base_test.py | 17 +++++- ptf/utest/BasicTest.py | 27 +++++++++ ptf/utest/LogConfig.py | 45 ++++++++++++++ ptf/utest/MockClient.py | 91 +++++++++++++++++++++++++++++ ptf/utest/TemplateTest.py | 53 +++++++++++++++++ test/sai_test/LogConfig.py | 45 ++++++++++++++ test/sai_test/sai_test_base.py | 17 +++++- 12 files changed, 384 insertions(+), 6 deletions(-) create mode 100644 ptf/LogConfig.py create mode 100644 ptf/utest/BasicTest.py create mode 100644 ptf/utest/LogConfig.py create mode 100644 ptf/utest/MockClient.py create mode 100644 ptf/utest/TemplateTest.py create mode 100644 test/sai_test/LogConfig.py diff --git a/meta/gensairpc.pl b/meta/gensairpc.pl index 402b8fdb3..b1a6df80d 100755 --- a/meta/gensairpc.pl +++ b/meta/gensairpc.pl @@ -90,7 +90,8 @@ [ 'verbose|v', 'Print more details', { default => 0 } ], [ 'mandatory-attrs', 'Make mandatory attributes obligatory in sai_adapter.py', { default => 0 } ], [ 'dev-utils:s', 'Generate additional development utils within the generated code. Additional options: [=log,zero]', { default => 0 } ], - [ 'skip_error:s', 'Skip test on specified error code. Additional options: [=-2]', { default => 0 } ], + [ 'skip_error:s', 'Skip test on specified error code. Additional options: [=-2]', { default => 0 } ], + [ 'adapter_logger', 'Enable the logger in sai_adapter, it will log all the method invocation.', { default => 0} ], [ 'attr-header', 'Generate additional header of attributes definitions (including object types)', { default => 0 } ], [ 'help|h', 'Print this help', { shortcircuit => 1 } ], ); @@ -116,6 +117,7 @@ my $mandatory_attrs = $args->mandatory_attrs; my $dev_utils = ( $args->dev_utils ne q{} ? $args->dev_utils : 1 ); my $skip_error = ( $args->skip_error ne q{} ? $args->skip_error : 1 ); +my $adapter_logger = ( $args->adapter_logger ne q{} ? $args->adapter_logger : 1 ); my $attr_header = $args->attr_header; # Configure SAI meta @@ -161,7 +163,8 @@ dbg => $dbg, mandatory_attrs => $mandatory_attrs, dev_utils => $dev_utils, - skip_error => $skip_error, + skip_error => $skip_error, + adapter_logger => $adapter_logger, templates_dir => $templates_dir }; diff --git a/meta/rpc/README.md b/meta/rpc/README.md index 9cfcb4b3a..0fb8fb31b 100644 --- a/meta/rpc/README.md +++ b/meta/rpc/README.md @@ -19,7 +19,8 @@ Optional arguments are useful for development purposes. | `-d` `--dump` | Dump all data to the file. **Should be used during development**. | | `--mandatory-attrs` | Make mandatory attributes obligatory in *sai\_adapter.py*. It removes `=None` from attributes, which are passed as arguments into python functions. Can be useful for debugging purposes, but since most of attributes are **optionally** mandatory, this is not as useful as it could be. | | `--dev-utils[=STR]` | Generate additional development utils within the generated code. Additional options: [=log,zero]. Useful for tests development and debugging. The generated code **should not** be committed. | -| `--skip_error[=STR]` | Skip test on specified error code. Additional options: [=-2]. The generated code **should not** be committed. | +| `--skip_error[=STR]` | Skip test on specified error code. Additional options: [=-2]. The generated code **should not** be committed. | +| `--adapter_logger` | Enable the logger in sai_adapter, it will log all the method invocation. | | `-h` `--help` | Print the help. | *gensairpc.pl* development diff --git a/meta/templates/sai_adapter.py.tt b/meta/templates/sai_adapter.py.tt index a5df12140..8ddcee7ff 100644 --- a/meta/templates/sai_adapter.py.tt +++ b/meta/templates/sai_adapter.py.tt @@ -432,6 +432,7 @@ client.[% function.thrift_name %]( [%- PROCESS decorate_method IF dev_utils -%] [%- PROCESS decorate_skip_test_on_error IF skip_error -%] + [%- PROCESS decorate_invocation_logger IF adapter_logger -%] [%- PROCESS function_header %] [%- PROCESS function_docstring %] @@ -489,6 +490,7 @@ Thrift SAI interface basic tests [%- PROCESS dev_utils_imports IF dev_utils -%] [%- PROCESS skip_test_on_error_imports IF skip_error -%] +[%- PROCESS invocation_logger_imports IF adapter_logger -%] from sai_thrift.ttypes import * from sai_thrift.sai_headers import * @@ -505,6 +507,7 @@ status = 0 [%- PROCESS dev_utils IF dev_utils -%] [%- PROCESS skip_error IF skip_error -%] +[%- PROCESS invocation_logger IF adapter_logger -%] [%- FOREACH api IN apis.keys.sort -%] [%- IF apis.$api.functions.size %] diff --git a/meta/templates/sai_adapter_utils.tt b/meta/templates/sai_adapter_utils.tt index 05ecb5e3d..9f9811d38 100644 --- a/meta/templates/sai_adapter_utils.tt +++ b/meta/templates/sai_adapter_utils.tt @@ -13,6 +13,11 @@ from unittest import SkipTest from ptf import testutils [% END -%] +[%- BLOCK invocation_logger_imports %] +import inspect +import logging +[% END -%] + [%- ######################################################################## -%] [%- ######################################################################## -%] @@ -31,6 +36,13 @@ from ptf import testutils [% PROCESS skip_test_on_error %] [% END -%] +[%- BLOCK invocation_logger %] + +# invocation_logger + +[% PROCESS invocation_logger_func %] +[% END -%] + [%- ######################################################################## -%] [%- ######################################################################## -%] @@ -207,6 +219,27 @@ def skip_test_on_error(errorcode=[-2]): return skip_test_on_error_decorator [%- END -%] +[%- BLOCK invocation_logger_func -%] +def invocation_logger(func): + """ + SAI interface invocation logger. + Use it to log all the invocated method in this sai_adapater. + """ + + def inner_logger(*args, **kwargs): + + args_name = inspect.getargspec(func)[0] + + args_dict = dict(zip(args_name, args)) + args_dict.update(kwargs) + logging.info("sai_adapter_invoke func:[{}] args: [{}]".format(func.__name__, args_dict)) + + args_values = args_dict.values() + return func(*args, **kwargs) + + return inner_logger +[%- END -%] + [%- ######################################################################## -%] [%- ######################################################################## -%] @@ -219,4 +252,8 @@ def skip_test_on_error(errorcode=[-2]): @skip_test_on_error([% IF skip_error %]errorcode=[[% skip_error %]][% END %]) [%- END -%] +[%- BLOCK decorate_invocation_logger %] +@invocation_logger +[%- END -%] + [%- ######################################################################## -%] diff --git a/ptf/LogConfig.py b/ptf/LogConfig.py new file mode 100644 index 000000000..423240a3e --- /dev/null +++ b/ptf/LogConfig.py @@ -0,0 +1,45 @@ +import logging +import os +import sys +from logging.handlers import RotatingFileHandler + +ROOT_DIR = os.path.dirname(os.path.abspath(__file__)) +LOG_FILE_DIR = os.path.join(ROOT_DIR, 'logs') +LOG_FILE_PATH = os.path.join(LOG_FILE_DIR, 'output.log') + + +def set_logging(loggerName='main'): + """Set the logger. + """ + + # Create formatters and add it to handlers + c_debug_format = '%(name)s - %(filename)s - %(levelname)s - %(message)s' + c_error_format = '%(filename)s - %(levelname)s - %(message)s' + f_format = '%(asctime)s - %(name)s - %(filename)s - %(levelname)s - %(message)s' + datafmt = '%m/%d/%Y %I:%M:%S %p' + + if not os.path.exists(LOG_FILE_DIR): + os.mkdir(LOG_FILE_DIR) + + # Create a custom logger + logger = logging.getLogger() + logger.name = loggerName + logger.setLevel(logging.INFO) + + file_formatter = logging.Formatter(f_format, datafmt) + + # Create handlers + # Add a new file handler + file_handler = logging.FileHandler(LOG_FILE_PATH) + file_handler.setLevel(logging.DEBUG) + file_handler.setFormatter(file_formatter) + logger.addHandler(file_handler) + + + # Add a new stream handler + console_formatter = logging.Formatter( + c_error_format, datafmt) + stream_handler = logging.StreamHandler() + stream_handler.setLevel(logging.ERROR) + stream_handler.setFormatter(console_formatter) + logger.addHandler(stream_handler) diff --git a/ptf/sai_base_test.py b/ptf/sai_base_test.py index 36823c513..9b1b07711 100644 --- a/ptf/sai_base_test.py +++ b/ptf/sai_base_test.py @@ -21,6 +21,7 @@ """ import os import time +import inspect from threading import Thread from collections import OrderedDict @@ -34,6 +35,7 @@ from thrift.protocol import TBinaryProtocol from sai_thrift import sai_rpc +import LogConfig from sai_utils import * import sai_thrift.sai_adapter as adapter @@ -53,7 +55,6 @@ class ThriftInterface(BaseTest): """ def setUp(self): super(ThriftInterface, self).setUp() - self.interface_to_front_mapping = {} self.port_map_loaded = False self.transport = None @@ -120,6 +121,7 @@ def createRpcClient(self): self.transport.open() + class ThriftInterfaceDataPlane(ThriftInterface): """ Sets up the thrift interface and dataplane @@ -155,6 +157,17 @@ class SaiHelperBase(ThriftInterfaceDataPlane): """ platform = 'common' + + def set_logger_name(self): + """ + Set Logger name as filename:classname + """ + + file_name = inspect.getfile(self.__class__) + class_name = self.__class__.__name__ + logger_name = "{}:{}".format(file_name, class_name) + LogConfig.set_logging(loggerName = logger_name) + def get_active_port_list(self): ''' @@ -294,7 +307,7 @@ def start_switch(self): def setUp(self): super(SaiHelperBase, self).setUp() - + self.set_logger_name() self.getSwitchPorts() # initialize switch self.start_switch() diff --git a/ptf/utest/BasicTest.py b/ptf/utest/BasicTest.py new file mode 100644 index 000000000..e769edc6f --- /dev/null +++ b/ptf/utest/BasicTest.py @@ -0,0 +1,27 @@ + +import unittest +import inspect + +import LogConfig + +""" +Base class of the unit test +""" + +class BasicMockedTest(unittest.TestCase): + """Basic test case, use to simualate the sai_base_test class + + """ + + def setUp(self): + unittest.TestCase.setUp(self) + + def set_logger_name(self): + """ + Set Logger name as filename:classname + """ + + file_name = inspect.getfile(self.__class__) + class_name = self.__class__.__name__ + logger_name = "{}:{}".format(file_name, class_name) + LogConfig.set_logging(loggerName = logger_name) diff --git a/ptf/utest/LogConfig.py b/ptf/utest/LogConfig.py new file mode 100644 index 000000000..423240a3e --- /dev/null +++ b/ptf/utest/LogConfig.py @@ -0,0 +1,45 @@ +import logging +import os +import sys +from logging.handlers import RotatingFileHandler + +ROOT_DIR = os.path.dirname(os.path.abspath(__file__)) +LOG_FILE_DIR = os.path.join(ROOT_DIR, 'logs') +LOG_FILE_PATH = os.path.join(LOG_FILE_DIR, 'output.log') + + +def set_logging(loggerName='main'): + """Set the logger. + """ + + # Create formatters and add it to handlers + c_debug_format = '%(name)s - %(filename)s - %(levelname)s - %(message)s' + c_error_format = '%(filename)s - %(levelname)s - %(message)s' + f_format = '%(asctime)s - %(name)s - %(filename)s - %(levelname)s - %(message)s' + datafmt = '%m/%d/%Y %I:%M:%S %p' + + if not os.path.exists(LOG_FILE_DIR): + os.mkdir(LOG_FILE_DIR) + + # Create a custom logger + logger = logging.getLogger() + logger.name = loggerName + logger.setLevel(logging.INFO) + + file_formatter = logging.Formatter(f_format, datafmt) + + # Create handlers + # Add a new file handler + file_handler = logging.FileHandler(LOG_FILE_PATH) + file_handler.setLevel(logging.DEBUG) + file_handler.setFormatter(file_formatter) + logger.addHandler(file_handler) + + + # Add a new stream handler + console_formatter = logging.Formatter( + c_error_format, datafmt) + stream_handler = logging.StreamHandler() + stream_handler.setLevel(logging.ERROR) + stream_handler.setFormatter(console_formatter) + logger.addHandler(stream_handler) diff --git a/ptf/utest/MockClient.py b/ptf/utest/MockClient.py new file mode 100644 index 000000000..1a0af2bbb --- /dev/null +++ b/ptf/utest/MockClient.py @@ -0,0 +1,91 @@ +class MockSuccessClient(): + + def sai_thrift_remove_acl_table(self, var): + return 0 + + def sai_thrift_create_switch(client, + init_switch=None, + hardware_access_bus=None, + platfrom_context=None, + register_read=None, + register_write=None, + switch_id=None, + max_system_cores=None, + system_port_config_list=None, + ingress_acl=None, + egress_acl=None, + restart_warm=None, + warm_recover=None, + switching_mode=None, + bcast_cpu_flood_enable=None, + mcast_cpu_flood_enable=None, + src_mac_address=None, + max_learned_addresses=None, + fdb_aging_time=None, + fdb_unicast_miss_packet_action=None, + fdb_broadcast_miss_packet_action=None, + fdb_multicast_miss_packet_action=None, + ecmp_default_hash_algorithm=None, + ecmp_default_hash_seed=None, + ecmp_default_symmetric_hash=None, + ecmp_hash_ipv4=None, + ecmp_hash_ipv4_in_ipv4=None, + ecmp_hash_ipv6=None, + lag_default_hash_algorithm=None, + lag_default_hash_seed=None, + lag_default_symmetric_hash=None, + lag_hash_ipv4=None, + lag_hash_ipv4_in_ipv4=None, + lag_hash_ipv6=None, + counter_refresh_interval=None, + qos_default_tc=None, + qos_dot1p_to_tc_map=None, + qos_dot1p_to_color_map=None, + qos_dscp_to_tc_map=None, + qos_dscp_to_color_map=None, + qos_tc_to_queue_map=None, + qos_tc_and_color_to_dot1p_map=None, + qos_tc_and_color_to_dscp_map=None, + switch_shell_enable=None, + switch_profile_id=None, + switch_hardware_info=None, + firmware_path_name=None, + switch_state_change_notify=None, + switch_shutdown_request_notify=None, + fdb_event_notify=None, + port_state_change_notify=None, + packet_event_notify=None, + fast_api_enable=None, + mirror_tc=None, + queue_pfc_deadlock_notify=None, + pfc_dlr_packet_action=None, + pfc_tc_dld_interval=None, + pfc_tc_dlr_interval=None, + tpid_outer_vlan=None, + tpid_inner_vlan=None, + crc_check_enable=None, + crc_recalculation_enable=None, + bfd_session_state_change_notify=None, + ecn_ect_threshold_enable=None, + vxlan_default_router_mac=None, + vxlan_default_port=None, + uninit_data_plane_on_removal=None, + tam_object_id=None, + tam_event_notify=None, + pre_shutdown=None, + nat_zone_counter_object_id=None, + nat_enable=None, + firmware_download_broadcast=None, + firmware_load_method=None, + firmware_load_type=None, + firmware_download_execute=None, + firmware_broadcast_stop=None, + firmware_verify_and_init_switch=None, + type=None, + macsec_object_id=None, + qos_mpls_exp_to_tc_map=None, + qos_mpls_exp_to_color_map=None, + qos_tc_and_color_to_mpls_exp_map=None, + failover_config_mode=None, + tunnel_objects_list=None): + return 0 diff --git a/ptf/utest/TemplateTest.py b/ptf/utest/TemplateTest.py new file mode 100644 index 000000000..0aaed4b36 --- /dev/null +++ b/ptf/utest/TemplateTest.py @@ -0,0 +1,53 @@ +from BasicTest import BasicMockedTest +from meta.sai_adapter import * +from MockClient import MockSuccessClient +import unittest + +""" +Class use to test the template. +Run command under folder 'meta' + perl -Irpc gensairpc.pl --adapter_logger --skip_error=-2 + copy sai_adaptor to ./test/saithriftv2/gen-py/sai + cd ./test/saithriftv2 + sudo python3 setup.py install +Install PTF + git clone https://github.com/p4lang/ptf.git + python3.7 setup.py install --single-version-externally-managed --record ./ptf_install.txt +Install scapy +Then check the result + +""" +ROOT_DIR = os.path.dirname(os.path.abspath(__file__)) +LOG_FILE_DIR = os.path.join(ROOT_DIR, 'logs') +LOG_FILE_PATH = os.path.join(LOG_FILE_DIR, 'output.log') + +class TestAdapterLogger(BasicMockedTest): + + def setUp(self): + BasicMockedTest.setUp(self) + self.client = MockSuccessClient() + + + def test_logger(self): + self.set_logger_name() + sai_thrift_remove_acl_table(self.client, 11111) + self.check_file_contains(LOG_FILE_PATH, 'acl_table_oid') + + sai_thrift_create_switch(self.client, + init_switch=True, + hardware_access_bus="11:11:11:11:11:11") + self.check_file_contains(LOG_FILE_PATH, 'hardware_access_bus') + + + def check_file_contains(self, file, content): + with open(file) as f: + datafile = f.readlines() + found = False + for line in datafile: + if content in line: + return True + return False + + +if __name__ == '__main__': + unittest.main() diff --git a/test/sai_test/LogConfig.py b/test/sai_test/LogConfig.py new file mode 100644 index 000000000..cb6520589 --- /dev/null +++ b/test/sai_test/LogConfig.py @@ -0,0 +1,45 @@ +import logging +import os +import sys +from logging.handlers import RotatingFileHandler + +ROOT_DIR = os.path.dirname(os.path.abspath(__file__)) +LOG_FILE_DIR = os.path.join(ROOT_DIR, 'logs') +LOG_FILE_PATH = os.path.join(LOG_FILE_DIR, 'output.log') + + +def set_logging(loggerName='main'): + """Set the logger. + """ + + # Create formatters and add it to handlers + c_debug_format = '%(name)s - %(filename)s - %(levelname)s - %(message)s' + c_error_format = '%(filename)s - %(levelname)s - %(message)s' + f_format = '%(asctime)s - %(name)s - %(filename)s - %(levelname)s - %(message)s' + datafmt = '%m/%d/%Y %I:%M:%S %p' + + if not os.path.exists(LOG_FILE_DIR): + os.mkdir(LOG_FILE_DIR) + + # Create a custom logger + logger = logging.getLogger() + logger.name = loggerName + logger.setLevel(logging.INFO) + + file_formatter = logging.Formatter(f_format, datafmt) + + # Create handlers + # Add a new file handler + file_handler = logging.FileHandler(LOG_FILE_PATH) + file_handler.setLevel(logging.DEBUG) + file_handler.setFormatter(file_formatter) + logger.addHandler(file_handler) + + + # Add a new stream handler + console_formatter = logging.Formatter( + c_error_format, datafmt) + stream_handler = logging.StreamHandler() + stream_handler.setLevel(logging.ERROR) + stream_handler.setFormatter(console_formatter) + logger.addHandler(stream_handler) diff --git a/test/sai_test/sai_test_base.py b/test/sai_test/sai_test_base.py index f198074f8..0e4fb0b13 100644 --- a/test/sai_test/sai_test_base.py +++ b/test/sai_test/sai_test_base.py @@ -55,6 +55,10 @@ from data_module.vlan import Vlan from sai_utils import * +import inspect + +import LogConfig + THRIFT_PORT = 9092 @@ -349,6 +353,15 @@ def __init__(self, *args, **kwargs): self.persist_helper = PersistHelper() self.ports_config = None + def set_logger_name(self): + """ + Set Logger name as filename:classname + """ + file_name = inspect.getfile(self.__class__) + class_name = self.__class__.__name__ + logger_name = "{}:{}".format(file_name, class_name) + LogConfig.set_logging(loggerName = logger_name) + def setUp(self, force_config=False, is_create_hostIf=True, @@ -363,8 +376,9 @@ def setUp(self, is_create_route_for_nhopgrp=False, wait_sec=5, skip_reason = None): - super(T0TestBase, self).setUp(skip_reason = skip_reason) + super(T0TestBase, self).setUp(skip_reason = skip_reason) + self.set_logger_name() # parse the port_config.ini, will create port, bridge port and host interface base on that file if 'port_config_ini' in self.test_params: self.ports_config = self.parsePortConfig(self.test_params['port_config_ini']) @@ -412,6 +426,7 @@ def setUp(self, self.t1_list = self.persist_helper.read_t1_list() self.servers = self.persist_helper.read_server_list() + def restore_fdb_config(self): """ Restore the FDB configurations.