diff --git a/context_logger/filter.py b/context_logger/filter.py index 2ecc018..895a5ee 100644 --- a/context_logger/filter.py +++ b/context_logger/filter.py @@ -2,6 +2,7 @@ # SPDX-FileCopyrightText: 2024 Attila Gombos # SPDX-License-Identifier: MIT +import json import socket from importlib.metadata import version, PackageNotFoundError from logging import Filter, LogRecord @@ -22,16 +23,19 @@ def filter(self, record: LogRecord) -> bool: record.msg = {self._message_field: record.msg % record.args if record.args else record.msg} record.args = () - record.msg['hostname'] = socket.gethostname() - record.msg['application'] = self._application_name - record.msg['app_version'] = self._get_application_version() + if isinstance(record.msg, dict): + record.msg['hostname'] = socket.gethostname() + record.msg['application'] = self._application_name + record.msg['app_version'] = self._get_application_version() - if 'process_name' in record.msg: - record.msg['process_name'] = record.processName + if 'process_name' in record.msg: + record.msg['process_name'] = record.processName - for key, value in self._global_context.items(): - if key not in record.msg: - record.msg[key] = str(value) + for key, value in self._global_context.items(): + if key not in record.msg: + record.msg[key] = str(value) + else: + record.msg = json.loads(str(record.msg)) except Exception as exception: print('Failed to handle log record:', exception) diff --git a/context_logger/logger.py b/context_logger/logger.py index 6e6714f..1948bee 100644 --- a/context_logger/logger.py +++ b/context_logger/logger.py @@ -2,6 +2,7 @@ # SPDX-FileCopyrightText: 2024 Attila Gombos # SPDX-License-Identifier: MIT +import json import logging.handlers import os import sys @@ -161,7 +162,14 @@ def _ensure_directory_exists(self, log_file_path: str) -> None: os.makedirs(directory) def _enrich_stdlib_log(self, _: logging.Logger, __: str, event_dict: dict[Any, Any]) -> dict[Any, Any]: - event_dict.update(event_dict['_record'].msg) + try: + message = event_dict['_record'].msg + if isinstance(message, dict): + event_dict.update(message) + else: + event_dict.update(json.loads(str(message))) + except Exception as exception: + print('Failed to handle stdlib log record:', exception) return event_dict diff --git a/tests/filterTest.py b/tests/filterTest.py index 9f2395a..57d7b87 100644 --- a/tests/filterTest.py +++ b/tests/filterTest.py @@ -70,6 +70,25 @@ def test_filter_handles_non_mapping_message(self): # Then self.assertTrue(result) self.assertEqual(123, record.msg) + print_mock.assert_not_called() + + def test_filter_handles_unexpected_version_lookup_error(self): + # Given + filter_ = ContextSetupFilter('example-app', 'message') + record = logging.LogRecord('ExampleClass', logging.INFO, __file__, 10, 'Hello', (), None) + + with patch('context_logger.filter.socket.gethostname', return_value='test-host'), \ + patch.object(filter_, '_get_application_version', side_effect=RuntimeError('boom')), \ + patch('builtins.print') as print_mock: + # When + result = filter_.filter(record) + + # Then + self.assertTrue(result) + self.assertEqual('Hello', record.msg.get('message')) + self.assertEqual('test-host', record.msg.get('hostname')) + self.assertEqual('example-app', record.msg.get('application')) + self.assertNotIn('app_version', record.msg) print_mock.assert_called_once() self.assertEqual('Failed to handle log record:', print_mock.call_args.args[0]) diff --git a/tests/loggerFallbackTest.py b/tests/loggerFallbackTest.py index 4d504ba..7fa69c3 100644 --- a/tests/loggerFallbackTest.py +++ b/tests/loggerFallbackTest.py @@ -133,6 +133,67 @@ def test_ensure_directory_exists_does_not_create_existing_directory(self): # Then makedirs_mock.assert_not_called() + def test_enrich_stdlib_log_updates_event_dict_from_mapping_message(self): + # Given + logger = Logger('example-app', 'INFO', None, 1024, 1, False, 'message') + record = MagicMock() + record.msg = {'message': 'ok', 'code': 7} + event_dict = {'_record': record, 'existing': True} + + # When + result = logger._enrich_stdlib_log(logging.getLogger('x'), 'info', event_dict) + + # Then + self.assertIs(result, event_dict) + self.assertEqual('ok', event_dict.get('message')) + self.assertEqual(7, event_dict.get('code')) + self.assertTrue(event_dict.get('existing')) + + def test_enrich_stdlib_log_updates_event_dict_from_json_message(self): + # Given + logger = Logger('example-app', 'INFO', None, 1024, 1, False, 'message') + record = MagicMock() + record.msg = '{"message": "ok", "code": 9}' + event_dict = {'_record': record} + + # When + result = logger._enrich_stdlib_log(logging.getLogger('x'), 'info', event_dict) + + # Then + self.assertIs(result, event_dict) + self.assertEqual('ok', event_dict.get('message')) + self.assertEqual(9, event_dict.get('code')) + + def test_enrich_stdlib_log_handles_invalid_message(self): + # Given + logger = Logger('example-app', 'INFO', None, 1024, 1, False, 'message') + record = MagicMock() + record.msg = object() + event_dict = {'_record': record, 'untouched': 'value'} + + with patch('builtins.print') as print_mock: + # When + result = logger._enrich_stdlib_log(logging.getLogger('x'), 'info', event_dict) + + # Then + self.assertIs(result, event_dict) + self.assertEqual('value', event_dict.get('untouched')) + print_mock.assert_called_once() + self.assertEqual('Failed to handle stdlib log record:', print_mock.call_args.args[0]) + + def test_get_foreign_prechain_appends_stdlib_enricher(self): + # Given + logger = Logger('example-app', 'INFO', None, 1024, 1, False, 'message') + logger._shared_processors = ['p1', 'p2'] + + # When + prechain = logger._get_foreign_prechain() + + # Then + self.assertEqual(['p1', 'p2'], prechain[:-1]) + self.assertIs(prechain[-1].__self__, logger) + self.assertIs(prechain[-1].__func__, Logger._enrich_stdlib_log) + if __name__ == '__main__': unittest.main()