Merge "Capture context in its own key for JSON-based formatters"

oslo_log/formatters.py

@@ -221,12 +221,18 @@ class JSONFormatter(logging.Formatter):
         for key in getattr(record, 'extra_keys', []):
             if key not in extra:
                 extra[key] = getattr(record, key)
-        # If we saved a context object, explode it into the extra
-        # dictionary because the values are more useful than the
+        # The context object might have been given from the logging call. if
+        # that was the case, it'll come in the 'extra' entry already. If not,
+        # lets use the context we fetched above. In either case, we explode it
+        # into the 'context' entry because the values are more useful than the
         # object reference.
-        if 'context' in extra:
-            extra.update(_dictify_context(context))
-            del extra['context']
+        if 'context' in extra and extra['context']:
+            message['context'] = _dictify_context(extra['context'])
+        elif context:
+            message['context'] = _dictify_context(context)
+        else:
+            message['context'] = {}
+        extra.pop('context', None)
         message['extra'] = extra
 
         if record.exc_info:
@@ -290,12 +296,18 @@ class FluentFormatter(logging.Formatter):
         for key in getattr(record, 'extra_keys', []):
             if key not in extra:
                 extra[key] = getattr(record, key)
-        # If we saved a context object, explode it into the extra
-        # dictionary because the values are more useful than the
+        # The context object might have been given from the logging call. if
+        # that was the case, it'll come in the 'extra' entry already. If not,
+        # lets use the context we fetched above. In either case, we explode it
+        # into the extra dictionary because the values are more useful than the
         # object reference.
-        if 'context' in extra:
-            extra.update(_dictify_context(context))
-            del extra['context']
+        if 'context' in extra and extra['context']:
+            message['context'] = _dictify_context(extra['context'])
+        elif context:
+            message['context'] = _dictify_context(context)
+        else:
+            message['context'] = {}
+        extra.pop('context', None)
         message['extra'] = extra
 
         if record.exc_info:

oslo_log/tests/unit/test_log.py

@@ -415,18 +415,38 @@ class JSONFormatterTestCase(LogTestBase):
                                        formatter=formatters.JSONFormatter)
         self._set_log_level_with_cleanup(self.log, logging.DEBUG)
 
-    def test_json(self):
+    def test_json_w_context_in_extras(self):
         test_msg = 'This is a %(test)s line'
         test_data = {'test': 'log'}
         local_context = _fake_context()
         self.log.debug(test_msg, test_data, key='value', context=local_context)
+        self._validate_json_data('test_json_w_context_in_extras', test_msg,
+                                 test_data, local_context)
 
+    def test_json_w_fetched_global_context(self):
+        test_msg = 'This is a %(test)s line'
+        test_data = {'test': 'log'}
+        local_context = _fake_context()
+        # NOTE we're not passing the context explicitly here. But it'll add the
+        # context to the extras anyway since the call to fake_context adds the
+        # context to the thread. The context will be fetched with the
+        # _update_record_with_context call that's done in the formatter.
+        self.log.debug(test_msg, test_data, key='value')
+        self._validate_json_data('test_json_w_fetched_global_context',
+                                 test_msg, test_data, local_context)
+
+    def _validate_json_data(self, testname, test_msg, test_data, ctx):
         data = jsonutils.loads(self.stream.getvalue())
         self.assertTrue(data)
         self.assertIn('extra', data)
+        self.assertIn('context', data)
         extra = data['extra']
+        context = data['context']
+        self.assertNotIn('context', extra)
         self.assertEqual('value', extra['key'])
-        self.assertEqual(local_context.user, extra['user'])
+        self.assertEqual(ctx.user, context['user'])
+        self.assertEqual(ctx.user_name, context['user_name'])
+        self.assertEqual(ctx.project_name, context['project_name'])
         self.assertEqual('test-json', data['name'])
 
         self.assertEqual(test_msg % test_data, data['message'])
@@ -434,7 +454,7 @@ class JSONFormatterTestCase(LogTestBase):
         self.assertEqual(test_data, data['args'])
 
         self.assertEqual('test_log.py', data['filename'])
-        self.assertEqual('test_json', data['funcname'])
+        self.assertEqual(testname, data['funcname'])
 
         self.assertEqual('DEBUG', data['levelname'])
         self.assertEqual(logging.DEBUG, data['levelno'])
@@ -563,8 +583,9 @@ class FluentFormatterTestCase(LogTestBase):
         self.assertIn('lineno', data)
         self.assertIn('extra', data)
         extra = data['extra']
+        context = data['context']
         self.assertEqual('value', extra['key'])
-        self.assertEqual(local_context.user, extra['user'])
+        self.assertEqual(local_context.user, context['user'])
         self.assertEqual('test-fluent', data['name'])
 
         self.assertEqual(test_msg % test_data, data['message'])

releasenotes/notes/add-context-section-0b2f411ec64f42f6.yaml

@@ -0,0 +1,6 @@
+---
+features:
+  - |
+    The JSON based formatters (namely JSONFormatter and FluentFormatter) now
+    output an extra section called 'context' that contains the context-related
+    keys and values, e.g. user, project and domain.