From 58bb3b81e76cfa6f46eaa57e686a7bac625c0f48 Mon Sep 17 00:00:00 2001
From: Christian Herdtweck <christian.herdtweck@intra2net.com>
Date: Fri, 24 Jun 2022 11:31:16 +0200
Subject: [PATCH] log_helper: Test and improve error-handling

---
 oletools/common/log_helper/_json_formatter.py   | 20 +++++++++++++++-----
 tests/common/log_helper/log_helper_test_main.py |  7 +++++++
 tests/common/log_helper/test_log_helper.py      |  6 ++++++
 3 files changed, 28 insertions(+), 5 deletions(-)

diff --git a/oletools/common/log_helper/_json_formatter.py b/oletools/common/log_helper/_json_formatter.py
index 1fae7e3..b1b9beb 100644
--- a/oletools/common/log_helper/_json_formatter.py
+++ b/oletools/common/log_helper/_json_formatter.py
@@ -32,15 +32,25 @@ class JsonFormatter(logging.Formatter):
         :py:class:`oletools.common.log_helper.OletoolsLoggerAdapter` or added here
         (for input from e.g. captured warnings, third-party libraries)
         """
-        msg = self.msg_formatter.format(record)
-        json_dict = dict(msg=msg.replace('\n', ' '), level=record.levelname)
+        json_dict = dict(msg='', level='', type='')
         try:
+            msg = self.msg_formatter.format(record)
+            json_dict['msg'] = msg.replace('\n', ' ')
+            json_dict['level'] = record.levelname
             json_dict['type'] = record.type
-        except AttributeError:
-            if record.name == 'py.warnings':   # this is the name of the logger
+        except AttributeError:     # most probably: record has no "type" field
+            if record.name == 'py.warnings':   # this is from python's warning-capture logger
                 json_dict['type'] = 'warning'
             else:
-                json_dict['type'] = 'msg'
+                json_dict['type'] = 'msg'      # message of unknown origin
+        except Exception as exc:
+            try:
+                json_dict['msg'] = "Ignore {0} when formatting '{1}': {2}".format(type(exc), record.msg, exc)
+            except Exception as exc2:
+                json_dict['msg'] = 'Caught {0} in logging'.format(str(exc2))
+            json_dict['type'] = 'log-warning'
+            json_dict['level'] = 'warning'
+
         formatted_message = '    ' + json.dumps(json_dict)
 
         if self._is_first_line:
diff --git a/tests/common/log_helper/log_helper_test_main.py b/tests/common/log_helper/log_helper_test_main.py
index e69f7c4..aeba555 100644
--- a/tests/common/log_helper/log_helper_test_main.py
+++ b/tests/common/log_helper/log_helper_test_main.py
@@ -50,6 +50,7 @@ def main(args):
     percent_autoformat = '%-autoformat' in args
     warn = 'warn' in args
     exc_info = 'exc-info' in args
+    wrong_log_args = 'wrong-log-args' in args
 
     log_helper_test_imported.logger.setLevel(logging.ERROR)
 
@@ -71,6 +72,12 @@ def main(args):
         except Exception:
             logger.exception('Caught exception')  # has exc_info=True
 
+    if wrong_log_args:
+        logger.info('Opening file /dangerous/file/with-%s-in-name')
+        logger.info('The result is %f')
+        logger.info('No result', 1.23)
+        logger.info('The result is %f', 'bla')
+
     log_helper.end_logging()
 
 
diff --git a/tests/common/log_helper/test_log_helper.py b/tests/common/log_helper/test_log_helper.py
index 1226743..4df2f64 100644
--- a/tests/common/log_helper/test_log_helper.py
+++ b/tests/common/log_helper/test_log_helper.py
@@ -224,6 +224,12 @@ class TestLogHelper(unittest.TestCase):
         self.assertIn('Traceback (most recent call last)', output)    # start of trace
         self.assertIn(TEST_FILE, output)        # part of trace
 
+    def test_json_wrong_args(self):
+        """Test that too many or missing args do not raise exceptions inside logger"""
+        output = self._run_test(['enable', 'as-json', 'wrong-log-args', 'info'])
+        json.loads(output)    # check that this does not raise, so json is valid
+        # do not care about actual contents of output
+
     def _assert_json_messages(self, output, messages):
         try:
             json_data = json.loads(output)
--
libgit2 0.21.4