PB-931 Fix stack_info formatting in JSON formatter

Add the stack info to the record instead of the message directly in JSON
formatter. This way it can be configured through the Django logging
facility

Author: schtibe

logging_utilities/formatters/json_formatter.py

@@ -349,14 +349,14 @@ def format(self, record):
             if not record.exc_text:
                 record.exc_text = self.formatException(record.exc_info)
 
+        if record.stack_info:
+            record.stack_info = self.formatStack(record.stack_info)
+
         message = self.formatMessage(record)
 
         if self.add_always_extra:
             self._add_extra_to_message(extra, message)
 
-        if record.stack_info:
-            message['stack_info'] = self.formatStack(record.stack_info)
-
         # When adding all extras, to avoid crash when a log message adds an extra with a non
         # serializable object, we add a default serializer.
         default = self.kwargs.pop('default', None)

tests/test_json_formatter.py

@@ -379,11 +379,8 @@ def test_stack_info(self):
             logger = logging.getLogger('test_formatter')
             self._configure_logger(
                 logger,
-                fmt=dictionary([
-                    ('levelname', 'levelname'),
-                    ('name', 'name'),
-                    ('message', 'message'),
-                ])
+                fmt=dictionary([('levelname', 'levelname'), ('name', 'name'),
+                                ('message', 'message'), ('stack_info', 'stack_info')])
             )
             logger.info('Message with stack info', stack_info=True)
         message = json.loads(ctx.output[0], object_pairs_hook=dictionary)
@@ -826,3 +823,41 @@ def test_exc_info_without_configuration(self):
                 ("message", "Error occurred"),  # no exc_text because it wasn't configured
             ])
         )
+
+    def test_stack_info_without_configuration(self):
+        """
+        Test that the stack_info doesn't appear in the record when it's
+        not configured, even though the log call records it
+        """
+        with self.assertLogs('test_formatter', level=logging.DEBUG) as ctx:
+            logger = logging.getLogger('test_formatter')
+            self._configure_logger(
+                logger,
+                fmt=dictionary([
+                    ('level', 'levelname'),
+                    ('request', ['request.path', 'request.method']),
+                    ('message', 'message'),
+                ]),
+                remove_empty=True,
+                ignore_missing=True
+            )
+
+            logger.info(
+                "Stack isn't wished for here",
+                exc_info=sys.exc_info(),
+                extra={'request': {
+                    'path': '/my/path', 'method': 'GET', 'scheme': 'https'
+                }},
+                # record the stack_info
+                stack_info=True
+            )
+
+        self.assertDictEqual(
+            json.loads(ctx.output[0], object_pairs_hook=dictionary),
+            dictionary([
+                ("level", "INFO"),
+                ("request", ["/my/path", "GET"]),
+                ("message",
+                 "Stack isn't wished for here"),  # no stack_info because it wasn't configured
+            ])
+        )