From: wahidw Date: Tue, 3 Nov 2020 06:08:24 +0000 (+0000) Subject: Add log formatting option and dynamic Log-Level change Implement MDC Log entry format... X-Git-Tag: 1.1.2~6 X-Git-Url: https://gerrit.o-ran-sc.org/r/gitweb?a=commitdiff_plain;h=426f943c7b035960955953031b8cf5d7a0200867;p=com%2Fpylog.git Add log formatting option and dynamic Log-Level change Implement MDC Log entry formatting options via environment variables and implement dynamic Log-Level change what makes possible to change the log level of a running process in a Docker container. Signed-off-by: wahidw Change-Id: Ia8efeb03ff8ac8a58ff2aacfd95f181f2b2f3555 --- diff --git a/docs/developer-guide.rst b/docs/developer-guide.rst index 89aa92a..33f9735 100644 --- a/docs/developer-guide.rst +++ b/docs/developer-guide.rst @@ -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 ------- diff --git a/mdclogpy/README.md b/mdclogpy/README.md index 1a05a07..41ea5b1 100644 --- a/mdclogpy/README.md +++ b/mdclogpy/README.md @@ -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 -------------------------- diff --git a/mdclogpy/mdclogpy/Logger.py b/mdclogpy/mdclogpy/Logger.py index 43c48e4..d83750e 100644 --- a/mdclogpy/mdclogpy/Logger.py +++ b/mdclogpy/mdclogpy/Logger.py @@ -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.""" diff --git a/mdclogpy/mdclogpy/__init__.py b/mdclogpy/mdclogpy/__init__.py index b48a450..a10358b 100644 --- a/mdclogpy/mdclogpy/__init__.py +++ b/mdclogpy/mdclogpy/__init__.py @@ -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) diff --git a/mdclogpy/tox.ini b/mdclogpy/tox.ini index 625bb6b..4dc4185 100644 --- a/mdclogpy/tox.ini +++ b/mdclogpy/tox.ini @@ -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 diff --git a/mdclogpy/tst/test_Logger.py b/mdclogpy/tst/test_Logger.py index 12a2543..2ea4b16 100644 --- a/mdclogpy/tst/test_Logger.py +++ b/mdclogpy/tst/test_Logger.py @@ -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) diff --git a/mdclogpy/tst/test_mdclogpy.py b/mdclogpy/tst/test_mdclogpy.py index ad7fd3a..ab21149 100644 --- a/mdclogpy/tst/test_mdclogpy.py +++ b/mdclogpy/tst/test_mdclogpy.py @@ -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 --- 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