Make JsonLogFormatter easier to extend (#37)

src/dockerflow/logging.py

@@ -82,36 +82,43 @@ def __init__(self, fmt=None, datefmt=None, style="%", logger_name="Dockerflow"):
         self.logger_name = logger_name
         self.hostname = socket.gethostname()
 
-    def format(self, record):
+    def is_value_jsonlike(self, value):
+        """
+        Return True if the value looks like JSON. Use only on strings.
+        """
+        return value.startswith('{') and value.endswith('}')
+
+    def convert_record(self, record):
         """
-        Map from Python LogRecord attributes to JSON log format fields
+        Convert a Python LogRecord attribute into a dict that follows MozLog
+        application logging standard.
 
         * from - https://docs.python.org/3/library/logging.html#logrecord-attributes
         * to - https://wiki.mozilla.org/Firefox/Services/Logging
         """
-        out = dict(
-            Timestamp=int(record.created * 1e9),
-            Type=record.name,
-            Logger=self.logger_name,
-            Hostname=self.hostname,
-            EnvVersion=self.LOGGING_FORMAT_VERSION,
-            Severity=self.SYSLOG_LEVEL_MAP.get(
+        out = {
+            'Timestamp': int(record.created * 1e9),
+            'Type': record.name,
+            'Logger': self.logger_name,
+            'Hostname': self.hostname,
+            'EnvVersion': self.LOGGING_FORMAT_VERSION,
+            'Severity': self.SYSLOG_LEVEL_MAP.get(
                 record.levelno, self.DEFAULT_SYSLOG_LEVEL
             ),
-            Pid=record.process,
-        )
+            'Pid': record.process,
+        }
 
         # Include any custom attributes set on the record.
         # These would usually be collected metrics data.
-        fields = dict()
+        fields = {}
         for key, value in record.__dict__.items():
             if key not in self.EXCLUDED_LOGRECORD_ATTRS:
                 fields[key] = value
 
         # Only include the 'msg' key if it has useful content
         # and is not already a JSON blob.
         message = record.getMessage()
-        if message and not message.startswith("{") and not message.endswith("}"):
+        if message and not self.is_value_jsonlike(message):
             fields["msg"] = message
 
         # If there is an error, format it for nice output.
@@ -120,7 +127,14 @@ def format(self, record):
             fields["traceback"] = safer_format_traceback(*record.exc_info)
 
         out["Fields"] = fields
+        return out
 
+    def format(self, record):
+        """
+        Format a Python LogRecord into a JSON string following MozLog
+        application logging standard.
+        """
+        out = self.convert_record(record)
         return json.dumps(out, cls=SafeJSONEncoder)
 
 

tests/test_logging.py

@@ -63,6 +63,7 @@ def test_basic_operation(caplog):
     caplog.set_level(logging.DEBUG)
     logging.debug(message_text)
     details = assert_records(caplog.records)
+    assert details == formatter.convert_record(caplog.records[0])
 
     assert "Timestamp" in details
     assert "Hostname" in details
@@ -79,6 +80,7 @@ def test_custom_paramters(caplog):
     logger = logging.getLogger("tests.test_logging")
     logger.warning("custom test %s", "one", extra={"more": "stuff"})
     details = assert_records(caplog.records)
+    assert details == formatter.convert_record(caplog.records[0])
 
     assert details["Type"] == "tests.test_logging"
     assert details["Severity"] == 4
@@ -124,6 +126,10 @@ def test_ignore_json_message(caplog):
     details = assert_records(caplog.records)
     assert "msg" not in details["Fields"]
 
+    assert formatter.is_value_jsonlike('{"spam": "eggs"}')
+    assert not formatter.is_value_jsonlike('{"spam": "eggs"')
+    assert not formatter.is_value_jsonlike('"spam": "eggs"}')
+
 
 # https://mana.mozilla.org/wiki/pages/viewpage.action?pageId=42895640
 JSON_LOGGING_SCHEMA = json.loads(