FastAPI Uvicorn logging in Production

Hello 🙋‍♂️,

Running a ⏩FastAPI ⏩ application in production is very easy and fast, but along the way some Uvicorn logs are lost.

In this article I will discuss how to write a custom UvicornWorker and to centralize your logging configuration into a single file.

To keep things as simple as possible I’ve put all my code in a single Python file.

import uvicorn as uvicorn
from fastapi import FastAPI, APIRouter

router = APIRouter(prefix="")

def create_app():
    fast_app = FastAPI()
    return fast_app

def read_root():
    return {"Hello": "World"}

if __name__ == '__main__':
    app = create_app()

Running the code will return a {"Hello": "World"} json when you visit the root endpoint / at 😁

When you check the console window, the following log lines are printed:

INFO:     Started server process [10276]
INFO:     Waiting for application startup.
INFO:     Application startup complete.
INFO:     Uvicorn running on (Press CTRL+C to quit)
INFO: - "GET / HTTP/1.1" 200 OK

Notice the Uvicorn log GET / HTTP/1.1″ 200 OK.

According to Uvicorn’s deployment docs we should run Uvicorn in a production settings with the following command: gunicorn -k uvicorn.workers.UvicornWorker main:create_app.

(venv2) ➜  FastAPILogging gunicorn -k uvicorn.workers.UvicornWorker main:create_app
[2021-05-17 22:10:44 +0300] [6250] [INFO] Starting gunicorn 20.1.0
[2021-05-17 22:10:44 +0300] [6250] [INFO] Listening at: (6250)
[2021-05-17 22:10:44 +0300] [6250] [INFO] Using worker: uvicorn.workers.UvicornWorker
[2021-05-17 22:10:44 +0300] [6252] [INFO] Booting worker with pid: 6252
[2021-05-17 22:10:45 +0300] [6252] [WARNING] ASGI app factory detected. Using it, but please consider setting the --factory flag explicitly.
[2021-05-17 22:10:45 +0300] [6252] [INFO] Started server process [6252]
[2021-05-17 22:10:45 +0300] [6252] [INFO] Waiting for application startup.
[2021-05-17 22:10:45 +0300] [6252] [INFO] Application startup complete.

Now, if we visit the root endpoint, the console won’t print “GET / HTTP/1.1” 200 OK anymore/ 🤦‍♂️.

To fix it we need a custom UvicornWorker ⚙ and a logging configuration file 🗃.

Create a new file and name it logging.yaml, then paste the following contents in it:

version: 1
disable_existing_loggers: false

format: "%(asctime)s - %(levelname)s - %(message)s"

class: logging.StreamHandler
formatter: standard
stream: ext://sys.stdout

propagate: true

level: INFO
handlers: [console]
propagate: no

This file will configure our root logger and our Uvicorn logger. To read more on the topic please see Python logging configuration.

Next, we will create a custom UvicornWorker class that will set log_config to the path of our logging.yaml file, to pass the logging configuration that we’ve just made to Uvicorn. 🦄

I added the following code in

class MyUvicornWorker(UvicornWorker):
        "log_config": "/mnt/c/Users/denis/PycharmProjects/FastAPILogging/logging.yaml",

▶ If we run the application with:

gunicorn -k main.MyUvicornWorker main:create_app

We should see the Uvicorn access logs printed in the console 🦄

(venv2) ➜  FastAPILogging gunicorn -k main.MyUvicornWorker main:create_app
[2021-05-17 22:31:28 +0300] [6278] [INFO] Starting gunicorn 20.1.0
[2021-05-17 22:31:28 +0300] [6278] [INFO] Listening at: (6278)
[2021-05-17 22:31:28 +0300] [6278] [INFO] Using worker: main.MyUvicornWorker
[2021-05-17 22:31:28 +0300] [6280] [INFO] Booting worker with pid: 6280
2021-05-17 22:31:28,185 - WARNING - ASGI app factory detected. Using it, but please consider setting the --factory flag explicitly.
2021-05-17 22:31:28,185 - INFO - Started server process [6280]
2021-05-17 22:31:28,185 - INFO - Waiting for application startup.
2021-05-17 22:31:28,185 - INFO - Application startup complete.
2021-05-17 22:31:30,129 - INFO - - "GET / HTTP/1.1" 200

Thanks for reading! 📚



Leave a Reply

Fill in your details below or click an icon to log in: Logo

You are commenting using your account. Log Out /  Change )

Google photo

You are commenting using your Google account. Log Out /  Change )

Twitter picture

You are commenting using your Twitter account. Log Out /  Change )

Facebook photo

You are commenting using your Facebook account. Log Out /  Change )

Connecting to %s

This site uses Akismet to reduce spam. Learn how your comment data is processed.