Add log formatting option and dynamic Log-Level change Implement MDC Log entry format... 69/4969/2
authorwahidw <abdulwahid.w@nokia.com>
Tue, 3 Nov 2020 06:08:24 +0000 (06:08 +0000)
committerwahidw <abdulwahid.w@nokia.com>
Thu, 12 Nov 2020 16:07:08 +0000 (16:07 +0000)
Signed-off-by: wahidw <abdulwahid.w@nokia.com>
Change-Id: Ia8efeb03ff8ac8a58ff2aacfd95f181f2b2f3555

docs/developer-guide.rst
mdclogpy/README.md
mdclogpy/mdclogpy/Logger.py
mdclogpy/mdclogpy/__init__.py
mdclogpy/tox.ini
mdclogpy/tst/test_Logger.py
mdclogpy/tst/test_mdclogpy.py
tox.ini

index 89aa92a..33f9735 100644 (file)
@@ -66,7 +66,7 @@ out of the process.
 
 *Example log output*
 
-`{"ts": 1559285893047, "crit": "INFO", "id": "myprog", "mdc": {"second key":"other value","mykey":"keyval"}, "msg": "Hello world!"}`
+`{"ts": 1603103945651, "crit": "ERROR", "id": "test.py", "mdc": {"SYSTEM_NAME": "Cloud-Space", "HOST_NAME": "master", "SERVICE_NAME": "TestApp", "CONTAINER_NAME": "Container-101", "POD_NAME": "POD-101"}, "msg": "Hello World!"}`
 
 Install
 -------
@@ -93,6 +93,7 @@ The library can be used in two ways shown below.
 
  ```python
    import mdclogpy
+   mdclogpy.mdclog_format_init(configmap_monitor=True) 
    mdclogpy.error("This is an error log")
  ```
 
@@ -103,11 +104,16 @@ The library can be used in two ways shown below.
  ```python
    from mdclogpy import Logger
    my_logger = Logger()
+   my_logger.mdclog_format_init(configmap_monitor=True)
    my_logger.error("This is an error log")
  ```
 
 A program can create several logger instances.
 
+mdclog_format_init() Adds the MDC log format with HostName, PodName, ContainerName, ServiceName,PID,CallbackNotifyforLogFieldChange
+
+Pass configmap_monitor = False in mdclog_format_init() function to stop dynamic log level change based on configmap.
+
 Logging Levels
 --------------
 .. code:: bash
@@ -165,6 +171,21 @@ Pylog API's
  def clean_mdc(self):
 
 
+7. Initialise Sep Logging format: 
+
+This api Initialzes mdclog print format using MDC Dictionary by extracting the environment variables in the calling process for “SYSTEM_NAME”, “HOST_NAME”, “SERVICE_NAME”, “CONTAINER_NAME”, “POD_NAME” & “CONFIG_MAP_NAME” mapped to HostName, ServiceName, ContainerName, Podname and Configuration-file-name of the services respectively.
+
+
+.. code:: bash
+
+ def mdclog_format_init(configmap_monitor=False):
+
+        Keyword arguments:
+        configmap_monitor -- Enables/Disables Dynamic log level change based on configmap
+                          -- Boolean values True/False can be passed as per requirement.
+
+
+
 License
 -------
 
index 1a05a07..41ea5b1 100644 (file)
@@ -25,7 +25,8 @@ out of the process.
 
 *Example log output*
 
-`{"ts": 1559285893047, "crit": "INFO", "id": "myprog", "mdc": {"second key":"other value","mykey":"keyval"}, "msg": "Hello world!"}`
+`{"ts": 1603103945651, "crit": "ERROR", "id": "test.py", "mdc": {"SYSTEM_NAME": "Cloud-Space", "HOST_NAME": "master", "SERVICE_NAME": "TestApp", "CONTAINER_NAME": "", "POD_NAME": ""}, "msg": "Hello World!"}`
+
 
 Install
 -------
@@ -51,6 +52,7 @@ The library can be used in two ways shown below.
 
 ```python
   import mdclogpy
+  mdclogpy.mdclog_format_init(configmap_monitor=True) 
   mdclogpy.error("This is an error log")
 ```
 
@@ -59,11 +61,16 @@ The library can be used in two ways shown below.
 ```python
   from mdclogpy import Logger
   my_logger = Logger()
+  my_logger.mdclog_format_init(configmap_monitor=True)
   my_logger.error("This is an error log")
 ```
 
 A program can create several logger instances.
 
+mdclog_format_init() Adds the MDC log format with HostName, PodName, ContainerName, ServiceName,PID,CallbackNotifyforLogFieldChange
+
+Pass configmap_monitor = False in mdclog_format_init() function to stop dynamic log level change based on configmap.
+
 
 Mapped Diagnostics Context
 --------------------------
index 43c48e4..d83750e 100644 (file)
@@ -30,6 +30,9 @@ from enum import IntEnum
 import sys
 import json
 import time
+import os
+import inotify.adapters
+import threading
 
 
 class Level(IntEnum):
@@ -58,7 +61,7 @@ class Logger():
     name -- name of the component. The name will appear as part of the log
             entries.
     """
-    def __init__(self, name: str = sys.argv[0], level: Level = Level.DEBUG):
+    def __init__(self, name: str = sys.argv[0], level: Level = Level.ERROR):
         """Initialize a Logger instance.
 
             Keyword arguments:
@@ -68,6 +71,22 @@ class Logger():
         self.procname = name
         self.current_level = level
         self.mdc = {}
+        
+
+    # Pass configmap_monitor = True to monitor configmap to change logs dynamically using configmap
+    def mdclog_format_init(self,configmap_monitor=False):
+
+        self.mdc = {"SYSTEM_NAME":"","HOST_NAME":"","SERVICE_NAME":"","CONTAINER_NAME":"","POD_NAME":""}
+        self.get_env_params_values()
+        try:
+            self.filename = os.environ['CONFIG_MAP_NAME']
+            self.dirname = str(self.filename[:self.filename.rindex('/')])
+            if configmap_monitor == True:
+                self.register_log_change_notify()
+            
+        except Exception as e:
+            print("Unable to Add Watch on ConfigMap File",e)
+
 
     def _output_log(self, log: str):
         """Output the log, currently to stdout."""
@@ -135,6 +154,90 @@ class Logger():
         value -- MDC value
         """
         self.mdc[key] = value
+        
+
+    def get_env_params_values(self):
+
+        try:
+            self.mdc['SYSTEM_NAME'] = os.environ['SYSTEM_NAME']
+        except:
+            self.mdc['SYSTEM_NAME'] = ""
+
+        try:
+            self.mdc['HOST_NAME'] = os.environ['HOST_NAME']
+        except:
+            self.mdc['HOST_NAME'] = ""
+
+        try:
+            self.mdc['SERVICE_NAME'] = os.environ['SERVICE_NAME']
+        except:
+            self.mdc['SERVICE_NAME'] = ""
+    
+        try:
+            self.mdc['CONTAINER_NAME'] = os.environ['CONTAINER_NAME']
+        except:
+            self.mdc['CONTAINER_NAME'] = ""
+
+        try:
+            self.mdc['POD_NAME'] = os.environ['POD_NAME']
+        except:
+            self.mdc['POD_NAME'] = ""
+
+
+    
+    def update_mdc_log_level_severity(self,level):
+        severity_level = Level.DEBUG
+
+        if(level == ""):
+            print("Invalid Log Level defined in ConfigMap")
+        elif((level.upper() == "ERROR") or (level.upper() == "ERR" )):
+            severity_level = Level.ERROR
+        elif((level.upper() == "WARNING") or (level.upper() == "WARN")):
+            severity_level = Level.WARNING
+        elif(level.upper() == "INFO"):
+            severity_level = Level.INFO
+        elif(level.upper() == "DEBUG"):
+            severity_level = Level.DEBUG
+        
+        self.set_level(severity_level)
+      
+        
+        
+
+
+    def parse_file(self):
+        src = open(self.filename,'r')
+        level = ""
+        for line in src:
+            if 'log-level:' in line:
+                level_tmp = str(line.split(':')[-1]).strip()
+                level = level_tmp
+                break
+        src.close()
+        self.update_mdc_log_level_severity(level)
+        
+
+
+
+    def monitor_loglevel_change_handler(self):
+        i = inotify.adapters.Inotify()
+        i.add_watch(self.dirname)
+        for event in i.event_gen():
+            if (event is not None) and ('IN_MODIFY' in str(event[1]) or 'IN_DELETE' in str(event[1])):
+                self.parse_file()
+
+
+    def register_log_change_notify(self):
+        t1 = threading.Thread(target=self.monitor_loglevel_change_handler)
+        t1.daemon = True
+        try:
+            t1.start() 
+        except (KeyboardInterrupt, SystemExit):
+            cleanup_stop_thread()
+            sys.exit()
+        
+
+
 
     def get_mdc(self, key: str) -> Value:
         """Return logger's MDC value with the given key or None."""
index b48a450..a10358b 100644 (file)
@@ -38,6 +38,10 @@ def log(level: Level, message: str):
     _root_logger.log(level, message)
 
 
+def mdclog_format_init(configmap_monitor=False):
+    _root_logger.mdclog_format_init(configmap_monitor)    
+
+
 def error(message: str):
     """Log an error message. Equals to log(ERROR, msg)."""
     _root_logger.log(Level.ERROR, message)
index 625bb6b..4dc4185 100644 (file)
@@ -26,6 +26,7 @@ deps=
     pytest
     coverage
     pytest-cov
+    inotify
 
 commands=
        pytest --junitxml xunit-results.xml --cov mdclogpy --cov-report xml --cov-report term-missing --cov-report html --cov-fail-under=70
index 12a2543..2ea4b16 100644 (file)
@@ -20,6 +20,8 @@
 import unittest
 from unittest.mock import patch
 import sys
+import os
+import time
 
 from mdclogpy import Logger
 from mdclogpy import Level
@@ -39,8 +41,8 @@ class TestMdcLog(unittest.TestCase):
 
     def test_that_get_level_returns_the_current_log_level(self):
 
-        # default level is DEBUG
-        self.assertEqual(self.logger.get_level(), Level.DEBUG)
+        # default level is ERROR
+        self.assertEqual(self.logger.get_level(), Level.ERROR)
         self.logger.set_level(Level.INFO)
         self.assertEqual(self.logger.get_level(), Level.INFO)
         self.logger.set_level(Level.WARNING)
@@ -115,7 +117,7 @@ class TestMdcLog(unittest.TestCase):
     def test_that_log_contains_correct_timestamp(self, output_mock, mock_time):
 
         mock_time.return_value = 1554806251.4388545
-        self.logger.info("timestamp test")
+        self.logger.error("timestamp test")
 
         logs = TestMdcLogUtils.get_logs_as_json(output_mock.call_args_list)
         self.assertEqual(logs[0]["ts"], 1554806251439)
@@ -123,8 +125,9 @@ class TestMdcLog(unittest.TestCase):
     @patch('mdclogpy.Logger._output_log')
     def test_that_log_contains_correct_message(self, output_mock):
 
-        self.logger.info("message test")
+        self.logger.error("message test")
         logs = TestMdcLogUtils.get_logs_as_json(output_mock.call_args_list)
+        print(logs)
         self.assertEqual(logs[0]["msg"], "message test")
 
     @patch('mdclogpy.Logger._output_log')
@@ -142,10 +145,12 @@ class TestMdcLog(unittest.TestCase):
 
     @patch('mdclogpy.Logger._output_log')
     def test_that_empty_mdc_is_logged_correctly(self, output_mock):
-
+        self.logger.mdclog_format_init(configmap_monitor=True)
         self.logger.error("empty mdc test")
         logs = TestMdcLogUtils.get_logs_as_json(output_mock.call_args_list)
-        self.assertEqual(logs[0]["mdc"], {})
+        self.assertEqual(logs[0]["mdc"], {'SYSTEM_NAME': '', 'HOST_NAME': '', 'SERVICE_NAME': '', 'CONTAINER_NAME': '', 'POD_NAME': ''})
+    
+
 
     @patch('mdclogpy.Logger._output_log')
     def test_that_mdc_values_are_logged_correctly(self, output_mock):
@@ -158,6 +163,21 @@ class TestMdcLog(unittest.TestCase):
         self.assertEqual(logs[0]["mdc"]["key1"], "value1")
         self.assertEqual(logs[0]["mdc"]["key2"], "value2")
 
+    @patch('mdclogpy.Logger._output_log')
+    def test_log_level_change_from_configmap_file(self,output_mock):
+        self.logger.mdclog_format_init(configmap_monitor=True)
+        self.logger.filename= '/tmp/log-level'
+        self.logger.dirname='/tmp'
+        self.logger.register_log_change_notify()
+        self.assertEqual(mdclogpy.get_level(), mdclogpy.Level.ERROR)        
+        src = open('/tmp/log-level','w')
+        src.write('log-level: debug')
+        src.close()
+        time.sleep(2)
+
+        self.assertEqual(self.logger.get_level(), 10)
+
+
     def test_that_mdc_values_can_be_added_and_removed(self):
 
         self.logger.add_mdc("key1", "value1")
@@ -183,8 +203,8 @@ class TestMdcLog(unittest.TestCase):
         mdclogpy.add_mdc("key", "value")
 
         logger1.error("error msg")
-        logger2.warning("warning msg")
-        mdclogpy.info("info msg")
+        logger2.error("warning msg")
+        mdclogpy.error("info msg")
 
         logs = TestMdcLogUtils.get_logs_as_json(output_mock.call_args_list)
         self.assertEqual(3, output_mock.call_count)
@@ -197,14 +217,14 @@ class TestMdcLog(unittest.TestCase):
         self.assertEqual(len(logs[0]["mdc"]), 2)
 
         self.assertEqual(logs[1]["id"], "logger2")
-        self.assertEqual(logs[1]["crit"], "WARNING")
+        self.assertEqual(logs[1]["crit"], "ERROR")
         self.assertEqual(logs[1]["msg"], "warning msg")
         self.assertEqual(logs[1]["mdc"]["logger2_key1"], "logger2_value1")
         self.assertEqual(logs[1]["mdc"]["logger2_key2"], "logger2_value2")
         self.assertEqual(len(logs[1]["mdc"]), 2)
 
         self.assertEqual(logs[2]["id"], sys.argv[0])
-        self.assertEqual(logs[2]["crit"], "INFO")
+        self.assertEqual(logs[2]["crit"], "ERROR")
         self.assertEqual(logs[2]["msg"], "info msg")
         self.assertEqual(logs[2]["mdc"]["key"], "value")
         self.assertEqual(len(logs[2]["mdc"]), 1)
index ad7fd3a..ab21149 100644 (file)
@@ -58,8 +58,7 @@ class TestMdcLog(unittest.TestCase):
 
     def test_that_root_logger_get_level_returns_the_current_log_level(self):
 
-        # default level is DEBUG
-        self.assertEqual(mdclogpy.get_level(), mdclogpy.Level.DEBUG)
+        
         mdclogpy.set_level(mdclogpy.Level.INFO)
         self.assertEqual(mdclogpy.get_level(), mdclogpy.Level.INFO)
         mdclogpy.set_level(mdclogpy.Level.WARNING)
diff --git a/tox.ini b/tox.ini
index ac38348..aa03284 100644 (file)
--- a/tox.ini
+++ b/tox.ini
@@ -18,6 +18,7 @@ deps =
     sphinxcontrib-httpdomain
     recommonmark
     lfdocs-conf
+    inotify
 
 commands =
     sphinx-build -W -b html -n -d {envtmpdir}/doctrees ./docs/ {toxinidir}/docs/_build/html
@@ -35,4 +36,5 @@ deps = sphinx
        sphinxcontrib-httpdomain
        recommonmark
        lfdocs-conf
+       inotify
 commands = sphinx-build -W -b linkcheck -d {envtmpdir}/doctrees ./docs/ {toxinidir}/docs/_build/linkcheck