log_helper: Capture warnings into logging

We set logging.captureWarnings to True and use our logging framework for python's builtin warnings logger. Warnings from that logger will have "type=warning" per default (as opposed to "type=msg").

log_helper: Capture warnings into logging
We set logging.captureWarnings to True and use our logging framework for python's builtin warnings logger. Warnings from that logger will have "type=warning" per default (as opposed to "type=msg").
Christian Herdtweck
1 parent 6bc04064
Showing 3 changed files with 31 additions and 5 deletions
oletools/common/log_helper/_json_formatter.py
oletools/common/log_helper/_logger_adapter.py
oletools/common/log_helper/log_helper.py
@@ -18,12 +18,22 @@ class JsonFormatter(logging.Formatter):
         the output JSON-compatible. The only exception is when printing the first line,
         so we need to keep track of it.
-        We assume that all input comes from the OletoolsLoggerAdapter which
-        ensures that there is a `type` field in the record. Otherwise will have
-        to add a try-except around the access to `record.type`.
+        The resulting text is just a json dump of the :py:class:`logging.LogRecord`
+        object that is received as input, so no %-formatting or similar is done. Raw
+        unformatted message and formatting arguments are contained in fields `msg` and
+        `args` of the output.
+
+        Arg `record` has a `type` field when created by `OletoolLoggerAdapter`. If not
+        (e.g. captured warnings or output from third-party libraries), we add one.
         """
         json_dict = dict(msg=record.msg.replace('\n', ' '), level=record.levelname)
-        json_dict['type'] = record.type
+        try:
+            json_dict['type'] = record.type
+        except AttributeError:
+            if record.name == 'py.warnings':   # this is the name of the logger
+                json_dict['type'] = 'warning'
+            else:
+                json_dict['type'] = 'msg'
         formatted_message = '    ' + json.dumps(json_dict)
         if self._is_first_line:
@@ -7,6 +7,7 @@ class OletoolsLoggerAdapter(logging.LoggerAdapter):
     Adapter class for all loggers returned by the logging module.
     """
     _json_enabled = None
+    _is_warn_logger = False   # this is always False
     def print_str(self, message, **kwargs):
         """
@@ -44,7 +45,10 @@ class OletoolsLoggerAdapter(logging.LoggerAdapter):
             kwargs['extra']['type'] = kwargs['type']
             del kwargs['type']    # downstream loggers cannot deal with this
         if 'type' not in kwargs['extra']:
-            kwargs['extra']['type'] = 'msg'   # type will be added to LogRecord
+            if self._is_warn_logger:
+                kwargs['extra']['type'] = 'warning'    # this will add field
+            else:
+                kwargs['extra']['type'] = 'msg'        # 'type' to LogRecord
         return msg, kwargs
     def set_json_enabled_function(self, json_enabled):
@@ -53,6 +57,12 @@ class OletoolsLoggerAdapter(logging.LoggerAdapter):
         """
         self._json_enabled = json_enabled
+    def set_warnings_logger(self):
+        """Make this the logger for warnings"""
+        # create a object attribute that shadows the class attribute which is
+        # always False
+        self._is_warn_logger = True
+
     def level(self):
         """Return current level of logger."""
         return self.logger.level
@@ -152,6 +152,11 @@ class LogHelper:
         self._use_json = use_json
         sys.excepthook = self._get_except_hook(sys.excepthook)
+        # make sure warnings do not mess up our output
+        logging.captureWarnings(True)
+        warn_logger = self.get_or_create_silent_logger('py.warnings')
+        warn_logger.set_warnings_logger()
+
         # since there could be loggers already created we go through all of them
         # and set their levels to 0 so they will use the root logger's level
         for name in self._all_names:
@@ -174,6 +179,7 @@ class LogHelper:
         # end logging
         self._all_names = set()
+        logging.captureWarnings(False)
         logging.shutdown()
         # end json list