diff --git a/tests/common/log_helper/log_helper_test_main.py b/tests/common/log_helper/log_helper_test_main.py index cd8cf6b..e69f7c4 100644 --- a/tests/common/log_helper/log_helper_test_main.py +++ b/tests/common/log_helper/log_helper_test_main.py @@ -49,6 +49,7 @@ def main(args): throw = 'throw' in args percent_autoformat = '%-autoformat' in args warn = 'warn' in args + exc_info = 'exc-info' in args log_helper_test_imported.logger.setLevel(logging.ERROR) @@ -64,6 +65,12 @@ def main(args): warnings.warn(ACTUAL_WARNING) log_helper_test_imported.warn() + if exc_info: + try: + raise Exception('This is an exception') + except Exception: + logger.exception('Caught exception') # has exc_info=True + 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 aa26037..1226743 100644 --- a/tests/common/log_helper/test_log_helper.py +++ b/tests/common/log_helper/test_log_helper.py @@ -17,8 +17,7 @@ from os.path import dirname, join, relpath, abspath from tests.test_utils import PROJECT_ROOT # test file we use as "main" module -TEST_FILE = relpath(join(dirname(abspath(__file__)), 'log_helper_test_main.py'), - PROJECT_ROOT) +TEST_FILE = join(dirname(abspath(__file__)), 'log_helper_test_main.py') # test file simulating a third party main module that only imports oletools TEST_FILE_3RD_PARTY = relpath(join(dirname(abspath(__file__)), @@ -27,6 +26,8 @@ TEST_FILE_3RD_PARTY = relpath(join(dirname(abspath(__file__)), PYTHON_EXECUTABLE = sys.executable +PERCENT_FORMAT_OUTPUT = 'The answer is 47.' + class TestLogHelper(unittest.TestCase): def test_it_doesnt_log_when_not_enabled(self): @@ -114,7 +115,7 @@ class TestLogHelper(unittest.TestCase): def test_percent_autoformat(self): """Test that auto-formatting of log strings with `%` works.""" output = self._run_test(['enable', '%-autoformat', 'info']) - self.assertIn('The answer is 47.', output) + self.assertIn(PERCENT_FORMAT_OUTPUT, output) def test_json_correct_on_exceptions(self): """ @@ -208,6 +209,21 @@ class TestLogHelper(unittest.TestCase): ]) self.assertEqual(output.strip(), expect) + def test_json_percent_formatting(self): + """Test that json-output has formatting args included in output.""" + output = self._run_test(['enable', 'as-json', '%-autoformat', 'info']) + json.loads(output) # check that this does not raise, so json is valid + self.assertIn(PERCENT_FORMAT_OUTPUT, output) + + def test_json_exception_formatting(self): + """Test that json-output has formatted exception info in output""" + output = self._run_test(['enable', 'as-json', 'exc-info', 'info']) + json.loads(output) # check that this does not raise, so json is valid + self.assertIn('Caught exception', output) # actual log message + self.assertIn('This is an exception', output) # message of caught exception + self.assertIn('Traceback (most recent call last)', output) # start of trace + self.assertIn(TEST_FILE, output) # part of trace + def _assert_json_messages(self, output, messages): try: json_data = json.loads(output)