Fastapi: [QUESTION] What is best way to override logging to use structlog?

[wshayes]

Description

How can I [...]? I'm using structlog for logging in the application to get JSON logs (for loading into centralized logging service). The FastAPI/Starlette?/uvicorn logging is using standard text-based logging. What is the best way to override that to use my structlog configuration?

Additional context

Here is my structlog setup if that is useful:

import sys
import logging

import structlog
import structlog._frames


def logging_setup(settings):
    log_level = settings.LOGGING

    logging.basicConfig(format="%(message)s", stream=sys.stdout, level=log_level)
    logger = logging.getLogger()
    logger.setLevel(log_level)

    def add_app_context(logger, method_name, event_dict):
        f, name = structlog._frames._find_first_app_frame_and_name(["logging", __name__])
        event_dict["file"] = f.f_code.co_filename
        event_dict["line"] = f.f_lineno
        event_dict["function"] = f.f_code.co_name
        return event_dict

    structlog.configure(
        logger_factory=structlog.stdlib.LoggerFactory(),
        processors=[
            structlog.stdlib.filter_by_level,
            structlog.stdlib.add_logger_name,
            structlog.stdlib.add_log_level,
            add_app_context,
            structlog.processors.TimeStamper(fmt="iso"),
            structlog.processors.JSONRenderer(indent=2, sort_keys=True),
        ],
    )

I'm getting a mix of logging results:

pynanopubstore    | Checking for script in /app/prestart.sh
pynanopubstore    | There is no script /app/prestart.sh
pynanopubstore    | INFO: Uvicorn running on http://0.0.0.0:80 (Press CTRL+C to quit)
pynanopubstore    | INFO: Started reloader process [1]
pynanopubstore    | 2019-03-12 19:05.17 Using config file: None
pynanopubstore    | HEAD http://dev.biodati.test:9200/nanopubstore [status:200 request:0.006s]
pynanopubstore    | Started server process [9]
pynanopubstore    | Waiting for application startup.


pynanopubstore    | ('172.18.0.5', 32940) - "GET /docs HTTP/1.1" 200
pynanopubstore    | ('172.18.0.5', 32940) - "GET /openapi.json HTTP/1.1" 200
pynanopubstore    | {
pynanopubstore    |   "doc_type": "nanopub",
pynanopubstore    |   "event": "will do ES search",
pynanopubstore    |   "file": "./services/search.py",
pynanopubstore    |   "from_": 0,
pynanopubstore    |   "function": "es_search",
pynanopubstore    |   "index": "nanopubstore",
pynanopubstore    |   "level": "info",
pynanopubstore    |   "line": 247,
pynanopubstore    |   "logger": "services.search",
pynanopubstore    |   "query": {
pynanopubstore    |     "query_string": {
pynanopubstore    |       "allow_leading_wildcard": true,
pynanopubstore    |       "default_field": "*",
pynanopubstore    |       "query": "this OR that"
pynanopubstore    |     }
pynanopubstore    |   },
pynanopubstore    |   "size": 50,
pynanopubstore    |   "timestamp": "2019-03-12T19:05:26.385863Z"
pynanopubstore    | }
pynanopubstore    | POST http://dev.biodati.test:9200/nanopubstore/nanopub/_search?size=50&from=0 [status:200 request:0.393s]
pynanopubstore    | ('172.18.0.5', 32940) - "POST /search HTTP/1.1" 200

[tiangolo]

Sorry for the delay @wshayes.

From what I see, you are using the official image. That runs a bash script (that logs the Checking for script in /app/prestart.sh, etc).

Then it runs Gunicorn, and then it runs worker processes of Uvicorn, that are the ones running your application.

For the bash script, you can copy it from the one on the image and add your own version, as long as it's on the same route /start.sh it will be used by default.

Then, to get the logger for Uvicorn, I think @euri10 mentioned the idea somewhere to use getLogger("uvicorn"). I think that should work, as Uvicorn seems to be using that since this PR: https://github.com/encode/uvicorn/pull/181/files#diff-c38be1191c50b7818c8001e3373155e6R54

[wshayes]

Thanks!