JSON Logging for Sanic in python

JSON Logging for Sanic

The other day I was running some containers on Amazon's ECS and logging to cloudwatch. I then learnt cloudwatch parses JSON logs so obviously I then wanted Sanic to log out JSON.

Ideally this'll be useful to people but if it isn't, raise an issue and we'll make it better :)

To install:

pip install sanic-json-logging

Look at examples/simple.py for a full working example, but this will essentially get you going

import sanic
from sanic_json_logging import setup_json_logging

app = sanic.Sanic(name="somename")
setup_json_logging(app)

setup_json_logging does the following:

changes the default log formatters to JSON ones
also filters out no Keepalive warnings
unless told otherwise, will change the asyncio task factory, to implement some rudimentary task-local storage.
installs pre and post request middleware. Pre-request middleware to time tasks and generate a uuid4 request id. Post-request middleware to emit access logs.
will use AWS X-Forwarded-For IPs in the access logs if present

If setup_json_logging changed the task factory, all tasks created from the request's task will contain the request ID. You can pass disable_json_access_log=True to the setup function which will disable the configuration of JSON access logging. Setting configure_task_local_storage to false will disable storing request IDs inside the task object which will

Currently I have it outputting access logs like

{
  "timestamp": "2018-06-09T17:42:52.195701Z",
  "level": "INFO",
  "method": "GET",
  "path": "/endpoint1",
  "remote": "127.0.0.1:33468",
  "user_agent": "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/67.0.3396.62 Safari/537.36",
  "host": "localhost:8000",
  "response_time": 0.0,
  "req_id": "795617c7-b514-4ed9-bb63-cc4fcd883c3d",
  "logger": "sanic.access",
  "status_code": 200,
  "length": 0,
  "type": "access"
}

And if you log to the root logger, inside a request, it'll look like this.

{
  "timestamp": "2018-06-09T17:42:52.195326Z",
  "level": "INFO",
  "message": "some informational message",
  "type": "log",
  "logger": "root",
  "filename": "simple.py",
  "lineno": 16,
  "req_id": "795617c7-b514-4ed9-bb63-cc4fcd883c3d"
}

By default this package logs Exceptions with tracebacks as strings, you might want to render the traceback as JSON aswell. To achieve this simply provide an alternate formatter. First install this package with its optional dependencies:

pip install sanic-json-logging[extratb]

Then inject another Formatter:

from sanic_json_logging import LOGGING_CONFIG_DEFAULTS as cfg

cfg["formatters"]["generic"]["class"] = "sanic_json_logging.formatters.JSONTracebackJSONFormatter"
setup_json_logging(app, disable_json_access_log=True, config=cfg)

After all your tracebacks are formatted properly as JSON:

{
  "timestamp": "2021-08-26T23:19:49.412293Z",
  "level": "ERROR",
  "message": "Exception occurred while handling uri: 'http://127.0.0.1:8000/'",
  "type": "exception",
  "logger": "sanic.error",
  "worker": 31915,
  "filename": "handlers.py",
  "lineno": 146,
  "traceback": {
    "exc_type": "Exception",
    "exc_msg": "foo",
    "exc_tb": {
      "frames": [
        {
          "func_name": "handle_request",
          "lineno": 770,
          "module_name": "sanic.app",
          "module_path": "/python3.9/site-packages/sanic/app.py",
          "lasti": 182,
          "line": "                    response = await response"
        },
        {
          "func_name": "root",
          "lineno": 20,
          "module_name": "api.general",
          "module_path": "/api/general.py",
          "lasti": 6,
          "line": "    raise Exception(\"foo\")"
        }
      ]
    }
  },
  "req_id": "f128370f-b949-44e7-bb94-4635bbcad486"
}