This logging setup configures Structlog to output pretty logs in development, and JSON log lines in production.
Then, you can use Structlog loggers or standard logging
loggers, and they both will be processed by the Structlog pipeline (see the hello()
endpoint for reference). That way any log generated by your dependencies will also be processed and enriched, even if they know nothing about Structlog!
Requests are assigned a correlation ID with the asgi-correlation-id
middleware (either captured from incoming request or generated on the fly).
All logs are linked to the correlation ID, and to the Datadog trace/span if instrumented.
This data "global to the request" is stored in context vars, and automatically added to all logs produced during the request thanks to Structlog.
You can add to these "global local variables" at any point in an endpoint with structlog.contextvars.bind_contextvars(customer_id=123)
. Any log sent after this call will contain this attribute, whether it comes from structlog or logging.
The duration of the request is also captured, and all technical information about the request (URL, method, client IP/port, status code) are logged as attributes.
In production, Uvicorn startup logs are silenced because they are printed before we have time to configure JSON logging (and log ingestion systems don't like unformatted logs 😅). Uvicorn standard access logs are disabled, and reimplemented using Structlog (to be formatted in JSON or in the console).
Install dependencies with Poetry.
Run in development:
uvicorn main:app --reload
and in production (to log in JSON format and instrument the code with Datadog):
LOG_JSON_FORMAT=true DD_TRACE_ENABLED=true ddtrace-run uvicorn main:app --host 0.0.0.0 --log-config uvicorn_disable_logging.json
I will add my references and inspirations soon.
The "duration" logged and returned in the header does not encompass the full duration of the request. The code could be moved to a higher middleware running earlier in the chain, to also capture the duration of "inner" middlewares such as the correlation-id middleware, or others...
If you install Rich or better-exceptions
, you will automagically get pretty formatted exception with context, variable values... Try it and see if you like it
There are some TODOs left in the code, you can suggest improvements in the comments 😄 The Datadog middleware is especially horrible, there must be a better way to add it manually. I also need to open an issue in Starlette comparing in which order middlewares are activated in different languages and frameworks, to try and make it more consistent with other ecosystems.
This code is available under the MIT license.
Why all the bother of the logging config for uvicorn with NullHandler when you could specify --no-access-log and probably use --log-level critical to get rid of almost all the other logs it may do?
Anyway, very nice recipe :)