Merge "JSONFormatter convert unserializable with repr()"

oslo_log/formatters.py

@@ -12,6 +12,7 @@
 
 import datetime
 import debtcollector
+import functools
 import itertools
 import logging
 import logging.config
@@ -32,6 +33,15 @@ if six.PY3:
     from functools import reduce
 
 
+try:
+    # Test if to_primitive() has the fallback parameter added
+    # in oslo.serialization 2.21.1
+    jsonutils.to_primitive(1, fallback=repr)
+    _HAVE_JSONUTILS_FALLBACK = True
+except TypeError:
+    _HAVE_JSONUTILS_FALLBACK = False
+
+
 def _dictify_context(context):
     if getattr(context, 'get_logging_values', None):
         return context.get_logging_values()
@@ -238,6 +248,15 @@ class JSONFormatter(logging.Formatter):
         if record.exc_info:
             message['traceback'] = self.formatException(record.exc_info)
 
+        if _HAVE_JSONUTILS_FALLBACK:
+            # Bug #1593641: If an object cannot be serialized to JSON, convert
+            # it using repr() to prevent serialization errors. Using repr() is
+            # not ideal, but serialization errors are unexpected on logs,
+            # especially when the code using logs is not aware that the
+            # JSONFormatter will be used.
+            convert = functools.partial(jsonutils.to_primitive, fallback=repr)
+            return jsonutils.dumps(message, default=convert)
+        else:
             return jsonutils.dumps(message)
 
 

oslo_log/tests/unit/test_log.py

@@ -541,6 +541,28 @@ class JSONFormatterTestCase(LogTestBase):
         self.assertIn('error_summary', data)
         self.assertEqual('', data['error_summary'])
 
+    def test_fallback(self):
+        if not formatters._HAVE_JSONUTILS_FALLBACK:
+            self.skipTest("need the fallback parameter of "
+                          "jsonutils.to_primitive() added in "
+                          "oslo_serialization 2.21.1")
+
+        class MyObject(object):
+            def __str__(self):
+                return 'str'
+
+            def __repr__(self):
+                return 'repr'
+
+        obj = MyObject()
+        self.log.debug('obj=%s', obj)
+
+        data = jsonutils.loads(self.stream.getvalue())
+        self.assertEqual('obj=str', data['message'])
+        # Bug #1593641: If an object of record.args cannot be serialized,
+        # convert it using repr() to prevent serialization error on logging.
+        self.assertEqual(['repr'], data['args'])
+
 
 def get_fake_datetime(retval):
     class FakeDateTime(datetime.datetime):

releasenotes/notes/jsonformatter-repr-fd616eb6fa6caeb3.yaml

@@ -0,0 +1,6 @@
+---
+fixes:
+  - |
+    The JSONFormatter formatter now converts unserializable objects with
+    repr() to prevent JSON serialization errors on logging. The fix requires
+    oslo.serialization 2.21.1 or newer. (Bug #1593641)