diff --git a/tests/common/log_helper/log_helper_test_imported.py b/tests/common/log_helper/log_helper_test_imported.py index b3777af..8820a3e 100644 --- a/tests/common/log_helper/log_helper_test_imported.py +++ b/tests/common/log_helper/log_helper_test_imported.py @@ -11,6 +11,8 @@ INFO_MESSAGE = 'imported: info log' WARNING_MESSAGE = 'imported: warning log' ERROR_MESSAGE = 'imported: error log' CRITICAL_MESSAGE = 'imported: critical log' +RESULT_MESSAGE = 'imported: result log' +RESULT_TYPE = 'imported: result' logger = log_helper.get_or_create_silent_logger('test_imported', logging.ERROR) @@ -21,3 +23,4 @@ def log(): logger.warning(WARNING_MESSAGE) logger.error(ERROR_MESSAGE) logger.critical(CRITICAL_MESSAGE) + logger.info(RESULT_MESSAGE, type=RESULT_TYPE) diff --git a/tests/common/log_helper/log_helper_test_main.py b/tests/common/log_helper/log_helper_test_main.py index 0f6057a..98375fb 100644 --- a/tests/common/log_helper/log_helper_test_main.py +++ b/tests/common/log_helper/log_helper_test_main.py @@ -9,6 +9,8 @@ INFO_MESSAGE = 'main: info log' WARNING_MESSAGE = 'main: warning log' ERROR_MESSAGE = 'main: error log' CRITICAL_MESSAGE = 'main: critical log' +RESULT_MESSAGE = 'main: result log' +RESULT_TYPE = 'main: result' logger = log_helper.get_or_create_silent_logger('test_main') @@ -50,6 +52,7 @@ def _log(): logger.warning(WARNING_MESSAGE) logger.error(ERROR_MESSAGE) logger.critical(CRITICAL_MESSAGE) + logger.info(RESULT_MESSAGE, type=RESULT_TYPE) log_helper_test_imported.log() diff --git a/tests/common/log_helper/test_log_helper.py b/tests/common/log_helper/test_log_helper.py index 87f579d..ec0a5be 100644 --- a/tests/common/log_helper/test_log_helper.py +++ b/tests/common/log_helper/test_log_helper.py @@ -61,6 +61,57 @@ class TestLogHelper(unittest.TestCase): log_helper_test_imported.CRITICAL_MESSAGE ]) + def test_logs_type_ignored(self): + """Run test script with logging enabled at info level. Want no type.""" + output = self._run_test(['enable', 'info']) + + expect = '\n'.join([ + 'INFO ' + log_helper_test_main.INFO_MESSAGE, + 'WARNING ' + log_helper_test_main.WARNING_MESSAGE, + 'ERROR ' + log_helper_test_main.ERROR_MESSAGE, + 'CRITICAL ' + log_helper_test_main.CRITICAL_MESSAGE, + 'INFO ' + log_helper_test_main.RESULT_MESSAGE, + 'INFO ' + log_helper_test_imported.INFO_MESSAGE, + 'WARNING ' + log_helper_test_imported.WARNING_MESSAGE, + 'ERROR ' + log_helper_test_imported.ERROR_MESSAGE, + 'CRITICAL ' + log_helper_test_imported.CRITICAL_MESSAGE, + 'INFO ' + log_helper_test_imported.RESULT_MESSAGE, + ]) + self.assertEqual(output, expect) + + def test_logs_type_in_json(self): + """Check type field is contained in json log.""" + output = self._run_test(['enable', 'as-json', 'info']) + + # convert to json preserving order of output + jout = json.loads(output) + + jexpect = [ + dict(type='msg', level='INFO', + msg=log_helper_test_main.INFO_MESSAGE), + dict(type='msg', level='WARNING', + msg=log_helper_test_main.WARNING_MESSAGE), + dict(type='msg', level='ERROR', + msg=log_helper_test_main.ERROR_MESSAGE), + dict(type='msg', level='CRITICAL', + msg=log_helper_test_main.CRITICAL_MESSAGE), + # this is the important entry (has a different "type" field): + dict(type=log_helper_test_main.RESULT_TYPE, level='INFO', + msg=log_helper_test_main.RESULT_MESSAGE), + dict(type='msg', level='INFO', + msg=log_helper_test_imported.INFO_MESSAGE), + dict(type='msg', level='WARNING', + msg=log_helper_test_imported.WARNING_MESSAGE), + dict(type='msg', level='ERROR', + msg=log_helper_test_imported.ERROR_MESSAGE), + dict(type='msg', level='CRITICAL', + msg=log_helper_test_imported.CRITICAL_MESSAGE), + # ... and this: + dict(type=log_helper_test_imported.RESULT_TYPE, level='INFO', + msg=log_helper_test_imported.RESULT_MESSAGE), + ] + self.assertEqual(jout, jexpect) + def test_json_correct_on_exceptions(self): """ Test that even on unhandled exceptions our JSON is always correct