From f7c40dbd7a946e6a88ec3fdf5812edca9be5940c Mon Sep 17 00:00:00 2001 From: richardyu Date: Sun, 13 Nov 2022 13:08:41 +0000 Subject: [PATCH] add invocation logger Signed-off-by: richardyu-ms --- 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 | 58 ++++++++++++++++++ ptf/sai_base_test.py | 15 ++++- ptf/utest/BasicTest.py | 28 +++++++++ ptf/utest/LogConfig.py | 58 ++++++++++++++++++ ptf/utest/MockClient.py | 91 +++++++++++++++++++++++++++++ ptf/utest/TemplateTest.py | 50 ++++++++++++++++ test/sai_test/LogConfig.py | 58 ++++++++++++++++++ test/sai_test/sai_test_base.py | 18 +++++- 12 files changed, 420 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 402b8fdb32..b1a6df80d2 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 9cfcb4b3a2..0fb8fb31b3 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 a5df121409..8ddcee7fff 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 05ecb5e3d5..9f9811d381 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 0000000000..0aa8730f7e --- /dev/null +++ b/ptf/LogConfig.py @@ -0,0 +1,58 @@ +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') + +global logger +logger = logging.getLogger() + + +class InfoFilter(logging.Filter): + def filter(self, rec): + return rec.levelno in (logging.DEBUG, logging.INFO, logging.WARN) + +def set_logging(): + # Create a custom logger + + logger.setLevel(level=logging.DEBUG) + + # Create handlers + console_debug_handler = logging.StreamHandler(sys.stdout) + console_error_handler = logging.StreamHandler() + if not os.path.exists(LOG_FILE_DIR): + os.mkdir(LOG_FILE_DIR) + + file_handler = RotatingFileHandler(LOG_FILE_PATH, maxBytes=20000000, backupCount=5) + + if os.path.exists(LOG_FILE_PATH): + '''rollover on each run''' + file_handler.doRollover() + + + console_debug_handler.setLevel(logging.INFO) + console_debug_handler.addFilter(InfoFilter()) + file_handler.setLevel(logging.INFO) + console_error_handler.setLevel(logging.ERROR) + + # Create formatters and add it to handlers + c_debug_format = logging.Formatter(fmt='%(name)s - %(filename)s - %(levelname)s - %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p') + c_error_format = logging.Formatter(fmt='%(filename)s - %(levelname)s - %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p') + f_format = logging.Formatter(fmt='%(asctime)s - %(name)s - %(filename)s - %(levelname)s - %(message)s', + datefmt='%m/%d/%Y %I:%M:%S %p') + + console_error_handler.setFormatter(c_error_format) + console_debug_handler.setFormatter(c_debug_format) + file_handler.setFormatter(f_format) + + # Add handlers to the logger + logger.addHandler(console_debug_handler) + logger.addHandler(file_handler) + logger.addHandler(console_error_handler) + + +def rollover_log(): + file_handler.doRollover() diff --git a/ptf/sai_base_test.py b/ptf/sai_base_test.py index 6feeee96d8..e84be85c22 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 +from LogConfig import logger 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,15 @@ 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) + def get_active_port_list(self): ''' @@ -294,7 +305,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 0000000000..807a892480 --- /dev/null +++ b/ptf/utest/BasicTest.py @@ -0,0 +1,28 @@ + +import unittest +import inspect + +from LogConfig import logger +import LogConfig + + + +class BasicMockedTest(unittest.TestCase): + """Basic test case, use to simualate the sai_base_test class + + """ + + def setUp(self): + unittest.TestCase.setUp(self) + self.set_logger_name() + + + def set_logger_name(self): + """ + Set Logger name as filename:classname + """ + LogConfig.set_logging() + file_name = inspect.getfile(self.__class__) + class_name = self.__class__.__name__ + logger.name = "{}:{}".format(file_name, class_name) + \ No newline at end of file diff --git a/ptf/utest/LogConfig.py b/ptf/utest/LogConfig.py new file mode 100644 index 0000000000..0aa8730f7e --- /dev/null +++ b/ptf/utest/LogConfig.py @@ -0,0 +1,58 @@ +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') + +global logger +logger = logging.getLogger() + + +class InfoFilter(logging.Filter): + def filter(self, rec): + return rec.levelno in (logging.DEBUG, logging.INFO, logging.WARN) + +def set_logging(): + # Create a custom logger + + logger.setLevel(level=logging.DEBUG) + + # Create handlers + console_debug_handler = logging.StreamHandler(sys.stdout) + console_error_handler = logging.StreamHandler() + if not os.path.exists(LOG_FILE_DIR): + os.mkdir(LOG_FILE_DIR) + + file_handler = RotatingFileHandler(LOG_FILE_PATH, maxBytes=20000000, backupCount=5) + + if os.path.exists(LOG_FILE_PATH): + '''rollover on each run''' + file_handler.doRollover() + + + console_debug_handler.setLevel(logging.INFO) + console_debug_handler.addFilter(InfoFilter()) + file_handler.setLevel(logging.INFO) + console_error_handler.setLevel(logging.ERROR) + + # Create formatters and add it to handlers + c_debug_format = logging.Formatter(fmt='%(name)s - %(filename)s - %(levelname)s - %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p') + c_error_format = logging.Formatter(fmt='%(filename)s - %(levelname)s - %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p') + f_format = logging.Formatter(fmt='%(asctime)s - %(name)s - %(filename)s - %(levelname)s - %(message)s', + datefmt='%m/%d/%Y %I:%M:%S %p') + + console_error_handler.setFormatter(c_error_format) + console_debug_handler.setFormatter(c_debug_format) + file_handler.setFormatter(f_format) + + # Add handlers to the logger + logger.addHandler(console_debug_handler) + logger.addHandler(file_handler) + logger.addHandler(console_error_handler) + + +def rollover_log(): + file_handler.doRollover() diff --git a/ptf/utest/MockClient.py b/ptf/utest/MockClient.py new file mode 100644 index 0000000000..bfeb8485fc --- /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 \ No newline at end of file diff --git a/ptf/utest/TemplateTest.py b/ptf/utest/TemplateTest.py new file mode 100644 index 0000000000..5cc991a5e7 --- /dev/null +++ b/ptf/utest/TemplateTest.py @@ -0,0 +1,50 @@ +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): + 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 0000000000..0aa8730f7e --- /dev/null +++ b/test/sai_test/LogConfig.py @@ -0,0 +1,58 @@ +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') + +global logger +logger = logging.getLogger() + + +class InfoFilter(logging.Filter): + def filter(self, rec): + return rec.levelno in (logging.DEBUG, logging.INFO, logging.WARN) + +def set_logging(): + # Create a custom logger + + logger.setLevel(level=logging.DEBUG) + + # Create handlers + console_debug_handler = logging.StreamHandler(sys.stdout) + console_error_handler = logging.StreamHandler() + if not os.path.exists(LOG_FILE_DIR): + os.mkdir(LOG_FILE_DIR) + + file_handler = RotatingFileHandler(LOG_FILE_PATH, maxBytes=20000000, backupCount=5) + + if os.path.exists(LOG_FILE_PATH): + '''rollover on each run''' + file_handler.doRollover() + + + console_debug_handler.setLevel(logging.INFO) + console_debug_handler.addFilter(InfoFilter()) + file_handler.setLevel(logging.INFO) + console_error_handler.setLevel(logging.ERROR) + + # Create formatters and add it to handlers + c_debug_format = logging.Formatter(fmt='%(name)s - %(filename)s - %(levelname)s - %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p') + c_error_format = logging.Formatter(fmt='%(filename)s - %(levelname)s - %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p') + f_format = logging.Formatter(fmt='%(asctime)s - %(name)s - %(filename)s - %(levelname)s - %(message)s', + datefmt='%m/%d/%Y %I:%M:%S %p') + + console_error_handler.setFormatter(c_error_format) + console_debug_handler.setFormatter(c_debug_format) + file_handler.setFormatter(f_format) + + # Add handlers to the logger + logger.addHandler(console_debug_handler) + logger.addHandler(file_handler) + logger.addHandler(console_error_handler) + + +def rollover_log(): + file_handler.doRollover() diff --git a/test/sai_test/sai_test_base.py b/test/sai_test/sai_test_base.py index adcf14b2a7..31be131648 100644 --- a/test/sai_test/sai_test_base.py +++ b/test/sai_test/sai_test_base.py @@ -55,6 +55,11 @@ from data_module.vlan import Vlan from sai_utils import * +import inspect + +from LogConfig import logger +import LogConfig + THRIFT_PORT = 9092 @@ -349,6 +354,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 + """ + LogConfig.set_logging() + file_name = inspect.getfile(self.__class__) + class_name = self.__class__.__name__ + logger.name = "{}:{}".format(file_name, class_name) + def setUp(self, force_config=False, is_create_hostIf=True, @@ -365,8 +379,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']) @@ -416,6 +431,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.