add invocation logger

Signed-off-by: richardyu-ms <richard.yu@microsoft.com>

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
 };
 

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

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 %]

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 -%]
+
 [%- ######################################################################## -%]

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()

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()

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)
+

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()