From 6bc04064530d2138f207be18ba7325863afd46b7 Mon Sep 17 00:00:00 2001 From: Christian Herdtweck Date: Thu, 2 May 2019 17:46:33 +0200 Subject: [PATCH] tests: Add warnings to log_helper test --- tests/common/log_helper/log_helper_test_imported.py | 8 ++++++++ tests/common/log_helper/log_helper_test_main.py | 13 ++++++++++++- tests/common/log_helper/test_log_helper.py | 28 ++++++++++++++++++++++++++++ 3 files changed, 48 insertions(+), 1 deletion(-) diff --git a/tests/common/log_helper/log_helper_test_imported.py b/tests/common/log_helper/log_helper_test_imported.py index 1be8181..45b41d7 100644 --- a/tests/common/log_helper/log_helper_test_imported.py +++ b/tests/common/log_helper/log_helper_test_imported.py @@ -4,6 +4,7 @@ by the main test file """ from oletools.common.log_helper import log_helper +import warnings DEBUG_MESSAGE = 'imported: debug log' INFO_MESSAGE = 'imported: info log' @@ -11,7 +12,10 @@ WARNING_MESSAGE = 'imported: warning log' ERROR_MESSAGE = 'imported: error log' CRITICAL_MESSAGE = 'imported: critical log' RESULT_MESSAGE = 'imported: result log' + RESULT_TYPE = 'imported: result' +ACTUAL_WARNING = 'Feature XYZ provided by this module might be deprecated at '\ + 'some point in the future ... or not' logger = log_helper.get_or_create_silent_logger('test_imported') @@ -27,3 +31,7 @@ def log(): logger.error(ERROR_MESSAGE) logger.critical(CRITICAL_MESSAGE) logger.info(RESULT_MESSAGE, type=RESULT_TYPE) + + +def warn(): + warnings.warn(ACTUAL_WARNING) diff --git a/tests/common/log_helper/log_helper_test_main.py b/tests/common/log_helper/log_helper_test_main.py index c82f9bc..cd8cf6b 100644 --- a/tests/common/log_helper/log_helper_test_main.py +++ b/tests/common/log_helper/log_helper_test_main.py @@ -2,6 +2,7 @@ import sys import logging +import warnings from tests.common.log_helper import log_helper_test_imported from oletools.common.log_helper import log_helper @@ -11,7 +12,9 @@ WARNING_MESSAGE = 'main: warning log' ERROR_MESSAGE = 'main: error log' CRITICAL_MESSAGE = 'main: critical log' RESULT_MESSAGE = 'main: result log' + RESULT_TYPE = 'main: result' +ACTUAL_WARNING = 'Warnings can pop up anywhere, have to be prepared!' logger = log_helper.get_or_create_silent_logger('test_main') @@ -24,7 +27,8 @@ def enable_logging(): def main(args): """ - Try to cover possible logging scenarios. For each scenario covered, here's the expected args and outcome: + Try to cover possible logging scenarios. For each scenario covered, here's + the expected args and outcome: - Log without enabling: [''] * logging when being imported - should never print - Log as JSON without enabling: ['as-json', ''] @@ -35,6 +39,8 @@ def main(args): * logging as JSON when being run as script - should log messages as JSON - Enable, log as JSON and throw: ['enable', 'as-json', 'throw', ''] * should produce JSON-compatible output, even after an unhandled exception + - Enable, log as JSON and warn: ['enable', 'as-json', 'warn', ''] + * should produce JSON-compatible output, even after a warning """ # the level should always be the last argument passed @@ -42,6 +48,7 @@ def main(args): use_json = 'as-json' in args throw = 'throw' in args percent_autoformat = '%-autoformat' in args + warn = 'warn' in args log_helper_test_imported.logger.setLevel(logging.ERROR) @@ -53,6 +60,10 @@ def main(args): if throw: raise Exception('An exception occurred before ending the logging') + if warn: + warnings.warn(ACTUAL_WARNING) + log_helper_test_imported.warn() + 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 b67b47e..9929f6a 100644 --- a/tests/common/log_helper/test_log_helper.py +++ b/tests/common/log_helper/test_log_helper.py @@ -142,6 +142,32 @@ class TestLogHelper(unittest.TestCase): self.assertIn('INFO:test_main:main: info log', output) self.assertIn('INFO:test_imported:imported: info log', output) + def test_json_correct_on_warnings(self): + """ + Test that even on warnings our JSON is always correct + """ + output = self._run_test(['enable', 'as-json', 'warn', 'warning']) + expected_messages = [ + log_helper_test_main.WARNING_MESSAGE, + log_helper_test_main.ERROR_MESSAGE, + log_helper_test_main.CRITICAL_MESSAGE, + log_helper_test_imported.WARNING_MESSAGE, + log_helper_test_imported.ERROR_MESSAGE, + log_helper_test_imported.CRITICAL_MESSAGE, + ] + + for msg in expected_messages: + self.assertIn(msg, output) + + # last two entries of output should be warnings + jout = json.loads(output) + self.assertEqual(jout[-2]['level'], 'WARNING') + self.assertEqual(jout[-1]['level'], 'WARNING') + self.assertEqual(jout[-2]['type'], 'warning') + self.assertEqual(jout[-1]['type'], 'warning') + self.assertIn(log_helper_test_main.ACTUAL_WARNING, jout[-2]['msg']) + self.assertIn(log_helper_test_imported.ACTUAL_WARNING, jout[-1]['msg']) + def _assert_json_messages(self, output, messages): try: json_data = json.loads(output) @@ -163,6 +189,8 @@ class TestLogHelper(unittest.TestCase): When arg `run_third_party` is `True`, we do not run the `TEST_FILE` as main moduel but the `TEST_FILE_3RD_PARTY` and return contents of `stderr` instead of `stdout`. + + TODO: use tests.utils.call_and_capture """ all_args = [PYTHON_EXECUTABLE, ] if run_third_party: -- libgit2 0.21.4