Add MozlogHandler that integrates renamed formatter (#112)

* Add MozlogHandler that integrates renamed formatter

* Remove unused fixture from test

* Slightly refactor logging test setup

- Pass handler and formatter as fixtures to tests
- Reset logging after each test

* Add tests to assert how `logger_name` is attached to records

* Ruff fixes

* Use formatter in `assert_records` assertions

* Set caplog to INFO in fastapi rid test

* Make assertions about LogRecord and formatted output

docs/django.rst

@@ -61,8 +61,8 @@ To install ``python-dockerflow``'s Django support please follow these steps:
     ]
 
 #. :ref:`Configure logging <django-logging>` to use the
-   :class:`~dockerflow.logging.JsonLogFormatter`
-   logging formatter for the ``request.summary`` logger (you may have to
+   :class:`~dockerflow.logging.MozlogHandler`
+   logging handler for the ``request.summary`` logger (you may have to
    extend your existing logging configuration!).
 
 .. _`Kubernetes liveness checks`: https://kubernetes.io/docs/tasks/configure-pod-container/configure-liveness-readiness-startup-probes/
@@ -405,20 +405,15 @@ spec:
 Logging
 -------
 
-Dockerflow provides a :class:`~dockerflow.logging.JsonLogFormatter` Python
-logging formatter class.
+Dockerflow provides a :class:`~dockerflow.logging.MozlogHandler` Python
+logging handler class. This handler formats logs according to the Mozlog schema
+and emits them to stdout.
 
 To use it, put something like this in your Django ``settings`` file and
 configure **at least** the ``request.summary`` logger that way::
 
     LOGGING = {
         'version': 1,
-        'formatters': {
-            'json': {
-                '()': 'dockerflow.logging.JsonLogFormatter',
-                'logger_name': 'myproject'
-            }
-        },
         'filters': {
             'request_id': {
                 '()': 'dockerflow.logging.RequestIdLogFilter',
@@ -427,8 +422,7 @@ configure **at least** the ``request.summary`` logger that way::
         'handlers': {
             'console': {
                 'level': 'DEBUG',
-                'class': 'logging.StreamHandler',
-                'formatter': 'json',
+                'class': 'dockerflow.logging.MozlogHandler',
                 'filters': ['request_id']
             },
         },

docs/fastapi.rst

@@ -54,7 +54,7 @@ To install ``python-dockerflow``'s FastAPI support please follow these steps:
 
    .. seealso:: :ref:`fastapi-versions` for more information
 
-#. Configure logging to use the ``JsonLogFormatter`` logging formatter for the
+#. Configure logging to use the ``MozlogHandler`` logging handler for the
    ``request.summary`` logger (you may have to extend your existing logging
    configuration), see :ref:`fastapi-logging` for more information.
 
@@ -280,8 +280,8 @@ spec:
 Logging
 -------
 
-Dockerflow provides a :class:`~dockerflow.logging.JsonLogFormatter` Python
-logging formatter class.
+Dockerflow provides a :class:`~dockerflow.logging.Mozlog` Python
+logging handler class.
 
 To use it, put something like this **BEFORE** your FastAPI app is initialized
 for at least the ``request.summary`` logger:
@@ -292,12 +292,6 @@ for at least the ``request.summary`` logger:
 
     dictConfig({
         'version': 1,
-        'formatters': {
-            'json': {
-                '()': 'dockerflow.logging.JsonLogFormatter',
-                'logger_name': 'myproject'
-            }
-        },
         'filters': {
             'request_id': {
                 '()': 'dockerflow.logging.RequestIdLogFilter',
@@ -306,9 +300,8 @@ for at least the ``request.summary`` logger:
         'handlers': {
             'console': {
                 'level': 'DEBUG',
-                'class': 'logging.StreamHandler',
+                'class': 'dockerflow.logging.MozlogHandler',
                 'filters': ['request_id'],
-                'formatter': 'json'
             },
         },
         'loggers': {

docs/flask.rst

@@ -56,7 +56,7 @@ To install ``python-dockerflow``'s Flask support please follow these steps:
 
    .. seealso:: :ref:`flask-versions` for more information
 
-#. Configure logging to use the ``JsonLogFormatter`` logging formatter for the
+#. Configure logging to use the ``MozlogHandler`` logging handler for the
    ``request.summary`` logger (you may have to extend your existing logging
    configuration), see :ref:`flask-logging` for more information.
 
@@ -425,8 +425,8 @@ spec:
 Logging
 -------
 
-Dockerflow provides a :class:`~dockerflow.logging.JsonLogFormatter` Python
-logging formatter class.
+Dockerflow provides a :class:`~dockerflow.logging.MozlogHandler` Python
+logging handler class.
 
 To use it, put something like this **BEFORE** your Flask app is initialized
 for at least the ``request.summary`` logger::
@@ -435,12 +435,6 @@ for at least the ``request.summary`` logger::
 
     dictConfig({
         'version': 1,
-        'formatters': {
-            'json': {
-                '()': 'dockerflow.logging.JsonLogFormatter',
-                'logger_name': 'myproject'
-            }
-        },
         'filters': {
             'request_id': {
                 '()': 'dockerflow.logging.RequestIdLogFilter',
@@ -449,8 +443,7 @@ for at least the ``request.summary`` logger::
         'handlers': {
             'console': {
                 'level': 'DEBUG',
-                'class': 'logging.StreamHandler',
-                'formatter': 'json',
+                'class': 'dockerflow.logging.MozlogHandler',
                 'filters': ['request_id']
             },
         },

docs/logging.rst

@@ -3,8 +3,8 @@
 Logging
 =======
 
-python-dockerflow provides a :class:`~dockerflow.logging.JsonLogFormatter`
-Python logging formatter that produces messages following the JSON schema
+python-dockerflow provides a :class:`~dockerflow.logging.MozlogHandler`
+Python logging handler that produces messages following the JSON schema
 for a common application logging format defined by the illustrious
 Mozilla Cloud Services group.
 
@@ -33,12 +33,6 @@ this::
 
     cfg = {
         'version': 1,
-        'formatters': {
-            'json': {
-                '()': 'dockerflow.logging.JsonLogFormatter',
-                'logger_name': 'myproject'
-            }
-        },
         'filters': {
             'request_id': {
                 '()': 'dockerflow.logging.RequestIdLogFilter',
@@ -47,8 +41,7 @@ this::
         'handlers': {
             'console': {
                 'level': 'DEBUG',
-                'class': 'logging.StreamHandler',
-                'formatter': 'json',
+                'class': 'dockerflow.logging.MozlogHandler',
                 'filters': ['request_id']
             },
         },
@@ -109,7 +102,7 @@ thing as the dictionary based configuratio above:
     filters = request_id
 
     [formatter_json]
-    class = dockerflow.logging.JsonLogFormatter
+    class = dockerflow.logging.MozlogFormatter
 
 Then load the ini file using the :mod:`logging` module function
 :func:`logging.config.fileConfig`:

docs/sanic.rst

@@ -53,7 +53,7 @@ To install ``python-dockerflow``'s Sanic support please follow these steps:
 
    .. seealso:: :ref:`sanic-versions` for more information
 
-#. Configure logging to use the ``JsonLogFormatter`` logging formatter for the
+#. Configure logging to use the ``MozlogHandler`` logging handler for the
    ``request.summary`` logger (you may have to extend your existing logging
    configuration), see :ref:`sanic-logging` for more information.
 
@@ -405,8 +405,8 @@ spec:
 Logging
 -------
 
-Dockerflow provides a :class:`~dockerflow.logging.JsonLogFormatter` Python
-logging formatter class.
+Dockerflow provides a :class:`~dockerflow.logging.MozlogFormatter` Python
+logging handler class.
 
 To use it, pass something like this to your Sanic app when it is initialized
 for at least the ``request.summary`` logger::
@@ -415,12 +415,6 @@ for at least the ``request.summary`` logger::
 
     log_config = {
         'version': 1,
-        'formatters': {
-            'json': {
-                '()': 'dockerflow.logging.JsonLogFormatter',
-                'logger_name': 'myproject'
-            }
-        },
         'filters': {
             'request_id': {
                 '()': 'dockerflow.logging.RequestIdLogFilter',
@@ -429,8 +423,7 @@ for at least the ``request.summary`` logger::
         'handlers': {
             'console': {
                 'level': 'DEBUG',
-                'class': 'logging.StreamHandler',
-                'formatter': 'json',
+                'class': 'dockerflow.logging.MozlogHandler',
                 'filters': ['request_id']
             },
         },
@@ -440,7 +433,7 @@ for at least the ``request.summary`` logger::
                 'level': 'DEBUG',
             },
         }
-    })
+    }
 
     sanic = Sanic(__name__, log_config=log)
 

src/dockerflow/fastapi/middleware.py

@@ -1,7 +1,6 @@
 from __future__ import annotations
 
 import logging
-import sys
 import time
 import urllib
 from typing import Any, Dict
@@ -14,7 +13,7 @@
     HTTPScope,
 )
 
-from ..logging import JsonLogFormatter, get_or_generate_request_id, request_id_context
+from ..logging import MozlogHandler, get_or_generate_request_id, request_id_context
 
 
 class RequestIdMiddleware:
@@ -57,9 +56,8 @@ def __init__(
         if logger is None:
             logger = logging.getLogger("request.summary")
             logger.setLevel(logging.INFO)
-            handler = logging.StreamHandler(sys.stdout)
+            handler = MozlogHandler()
             handler.setLevel(logging.INFO)
-            handler.setFormatter(JsonLogFormatter())
             logger.addHandler(handler)
         self.logger = logger
 

src/dockerflow/logging.py

@@ -9,17 +9,31 @@
 import sys
 import traceback
 import uuid
+import warnings
 from contextvars import ContextVar
 from typing import ClassVar, Optional
 
 
+class MozlogHandler(logging.StreamHandler):
+    def __init__(self, stream=None, name="Dockerflow"):
+        if stream is None:
+            stream = sys.stdout
+        super().__init__(stream=stream)
+        self.logger_name = name
+        self.setFormatter(MozlogFormatter())
+
+    def emit(self, record):
+        record.logger_name = self.logger_name
+        super().emit(record)
+
+
 class SafeJSONEncoder(json.JSONEncoder):
     def default(self, o):
         return repr(o)
 
 
-class JsonLogFormatter(logging.Formatter):
-    """Log formatter that outputs machine-readable json.
+class MozlogFormatter(logging.Formatter):
+    """Log formatter that outputs json structured according to the Mozlog schema.
 
     This log formatter outputs JSON format messages that are compatible with
     Mozilla's standard heka-based log aggregation infrastructure.
@@ -58,9 +72,10 @@ class JsonLogFormatter(logging.Formatter):
             "levelname",
             "levelno",
             "lineno",
+            "logger_name",
+            "message",
             "module",
             "msecs",
-            "message",
             "msg",
             "name",
             "pathname",
@@ -75,15 +90,7 @@ class JsonLogFormatter(logging.Formatter):
     )
 
     def __init__(self, fmt=None, datefmt=None, style="%", logger_name="Dockerflow"):
-        parent_init = logging.Formatter.__init__
-        # The style argument was added in Python 3.1 and since
-        # the logging configuration via config (ini) files uses
-        # positional arguments we have to do a version check here
-        # to decide whether to pass the style argument or not.
-        if sys.version_info[:2] < (3, 1):
-            parent_init(self, fmt, datefmt)
-        else:
-            parent_init(self, fmt=fmt, datefmt=datefmt, style=style)
+        super().__init__(fmt=fmt, datefmt=datefmt, style=style)
         self.logger_name = logger_name
         self.hostname = socket.gethostname()
 
@@ -104,7 +111,7 @@ def convert_record(self, record):
         out = {
             "Timestamp": int(record.created * 1e9),
             "Type": record.name,
-            "Logger": self.logger_name,
+            "Logger": getattr(record, "logger_name", self.logger_name),
             "Hostname": self.hostname,
             "EnvVersion": self.LOGGING_FORMAT_VERSION,
             "Severity": self.SYSLOG_LEVEL_MAP.get(
@@ -143,6 +150,15 @@ def format(self, record):
         return json.dumps(out, cls=SafeJSONEncoder)
 
 
+class JsonLogFormatter(MozlogFormatter):
+    def __init__(self, *args, **kwargs):
+        warnings.warn(
+            "JsonLogFormatter has been deprecated. Use MozlogFormatter instead",
+            DeprecationWarning,
+        )
+        super().__init__(*args, **kwargs)
+
+
 def safer_format_traceback(exc_typ, exc_val, exc_tb):
     """Format an exception traceback into safer string.
     We don't want to let users write arbitrary data into our logfiles,