diff --git a/logtail/frame.py b/logtail/frame.py index 4820c76..49ffb4d 100644 --- a/logtail/frame.py +++ b/logtail/frame.py @@ -10,9 +10,6 @@ def create_frame(record: logging.LogRecord, message: str, context: LogtailContext, include_extra_attributes: bool = False) -> dict[str, Any]: r = record.__dict__ - # Django sends a request object in the record, which is not JSON serializable - if "request" in r and not isinstance(r["request"], (dict, list, bool, int, float, str)) : - del r["request"] frame: dict[str, Any] = {} frame['dt'] = datetime.fromtimestamp(r['created'], timezone.utc).isoformat() frame['level'] = _levelname(r['levelname']) @@ -58,6 +55,10 @@ def _parse_custom_events(record: logging.LogRecord, include_extra_attributes: bo for key, val in record.__dict__.items(): if key in default_keys: continue + # Django sends its request object in the record, which is not JSON serializable. It is + # left out of the frame but kept on the record, which every later handler receives too. + if key == 'request' and not isinstance(val, (dict, list, bool, int, float, str)): + continue if not include_extra_attributes and not isinstance(val, dict): continue events[key] = val diff --git a/tests/test_formatter.py b/tests/test_formatter.py index 52b745c..9f4545e 100644 --- a/tests/test_formatter.py +++ b/tests/test_formatter.py @@ -6,6 +6,7 @@ import json import unittest import pdb +import logging.handlers import logging import logtail @@ -102,6 +103,21 @@ def test_format_with_custom_default_json_encoder(self): self.assertEqual(frame['message'], 'goodbye') self.assertEqual(frame['context']['data'], {'not_encodable': ''}) + def test_format_leaves_the_django_request_on_the_record_for_the_next_handler(self): + formatter = logtail.LogtailFormatter(context=self.context) + logger, loglines = logger_and_lines(formatter) + next_handler = logging.handlers.BufferingHandler(capacity=10) + logger.addHandler(next_handler) + request = Dummy() # stands in for a Django HttpRequest + + logger.error('Internal Server Error: /orders', extra={'status_code': 500, 'request': request}) + + line = self._check_and_get_line(loglines) + frame = json.loads(line) + self.assertEqual(frame['status_code'], 500) + self.assertNotIn('request', frame) + self.assertIs(next_handler.buffer[0].request, request) + class Dummy(object): """ Because this is a custom class, it cannot be encoded by the default JSONEncoder. """ diff --git a/tests/test_frame.py b/tests/test_frame.py index c52e770..ecc9874 100644 --- a/tests/test_frame.py +++ b/tests/test_frame.py @@ -51,3 +51,24 @@ def test_create_frame_keeps_the_absolute_path_when_the_file_is_on_another_drive( frame = create_frame(log_record, log_record.getMessage(), LogtailContext()) self.assertEqual(frame['context']['runtime']['file'], 'D:\\workspace\\app\\main.py') + + def test_create_frame_leaves_a_django_request_on_the_record(self): + # Django logs its request as `extra={'request': request}`, and the same record goes on to + # every later handler, so the frame omits the request without deleting it from the record. + log_record = logging.LogRecord("logtail-test", 40, "/some/path", 10, "Internal Server Error: /orders", [], None) + request = object() + log_record.request = request + + frame = create_frame(log_record, log_record.getMessage(), LogtailContext(), include_extra_attributes=True) + + self.assertNotIn('request', frame) + self.assertIs(log_record.request, request) + + def test_create_frame_leaves_a_none_request_on_the_record(self): + log_record = logging.LogRecord("logtail-test", 40, "/some/path", 10, "Internal Server Error: /orders", [], None) + log_record.request = None + + frame = create_frame(log_record, log_record.getMessage(), LogtailContext(), include_extra_attributes=True) + + self.assertNotIn('request', frame) + self.assertIn('request', log_record.__dict__) diff --git a/tests/test_handler.py b/tests/test_handler.py index 2c7f87f..ec04729 100644 --- a/tests/test_handler.py +++ b/tests/test_handler.py @@ -5,6 +5,7 @@ import time import threading import unittest +import logging.handlers import logging from unittest.mock import patch @@ -192,6 +193,23 @@ def test_error_suppression(self, MockWorker): handler.raise_exceptions = False logger.critical('hello') + @patch('logtail.handler.FlushWorker') + def test_emit_leaves_the_django_request_on_the_record_for_the_next_handler(self, MockWorker): + handler = LogtailHandler(source_token=self.source_token, buffer_capacity=1) + next_handler = logging.handlers.BufferingHandler(capacity=10) + logger = logging.getLogger(__name__) + logger.handlers = [] + logger.addHandler(handler) + logger.addHandler(next_handler) + request = UnserializableObject() # stands in for a Django HttpRequest + + logger.error('Internal Server Error: /orders', extra={'status_code': 500, 'request': request}) + + log_entry = handler.pipe.get() + self.assertEqual(log_entry['message'], 'Internal Server Error: /orders') + self.assertNotIn('request', log_entry) + self.assertIs(next_handler.buffer[0].request, request) + @patch('logtail.handler.FlushWorker') def test_can_send_unserializable_extra_data(self, MockWorker): buffer_capacity = 1