Logging

Logging#

Sources:

Set up#

from requests import get

The following cell runs a Docker container that utilizes a specified file to build a FastAPI application.

Note here the whole logging_files folder is mounted as a volume, which is not typical for the fastapi section. This is because we’ll be working with configs as separate files.

!docker run --rm -itd\
    --name test_container\
    -v ./logging_files/:/app/\
    -p 8000:8000 \
    fastapi_experiment \
    uvicorn --host 0.0.0.0 --reload app.app:app

00c6b2ba8d2a6b07131e0b69ec503747c6b5771094d1287afca9e56c780e4ffd

Don’t forget to stop the container.

!docker stop test_container

test_container

View logs#

Let’s see what the default logs of the fast api look like. We will make an application to write something to the console and then extract it from the docker container.

In the following cell we’ve just defined a simple fastapi program that throws a HTTPException if called with a False argument.

%%writefile logging_files/app.py
from fastapi import FastAPI, HTTPException

app = FastAPI()

@app.get("/{is_ok}")
def handle(is_ok: bool):
    if is_ok:
        return "im fine"
    else:
        raise HTTPException(status_code=404, detail="Item not found")

Overwriting logging_files/app.py

Now let’s send some requests to the application and view it’s log last lines:

get("http://localhost:8000/True")
get("http://localhost:8000/False")
!docker logs --tail 2 test_container

INFO:     172.17.0.1:60808 - "GET /True HTTP/1.1" 200 OK
INFO:     172.17.0.1:60816 - "GET /False HTTP/1.1" 404 Not Found

Loggers#

The following fastapi program returns all available loggers in the fast api.

%%writefile logging_files/app.py
import logging
from fastapi import FastAPI, HTTPException

app = FastAPI()

@app.get("/")
def handle():
    return [
        name for name in 
        logging.root.manager.loggerDict.keys()
    ]

Overwriting logging_files/app.py

So let’s check what does we have.

response = get("http://localhost:8000")
response.content

b'["concurrent.futures","concurrent","asyncio","uvicorn.error","uvicorn","uvicorn.access","fastapi"]'

In my opinion, the most interesting logs for us here are fastapi, unicorn, unicorn.error, unicorn.acess and fastapi.

Configure loggers#

You can use the fastapi and uvicorn loggers just like any other logging package logger.

The following cell defines the logging config that makes uvicorn print its logs to the file.

%%writefile logging_files/uvicorn_logging.ini
[loggers]
keys=root,uvicorn

[handlers]
keys=console,file

[formatters]
keys=generic

[logger_root]
level=INFO
handlers=console

[logger_uvicorn]
level=DEBUG
handlers=file
qualname=uvicorn
propagate=0

[handler_console]
class=StreamHandler
formatter=generic
args=(sys.stderr,)

[handler_file]
class=FileHandler
formatter=generic
args=('./app/uvicorn.log', 'a')

[formatter_generic]
format=%(asctime)s - %(levelname)s - %(message)s
datefmt=%Y-%m-%d %H:%M:%S

Overwriting logging_files/uvicorn_logging.ini

Now define new programm that apply config showen before to logging module.

%%writefile logging_files/app.py
import logging
import logging.config
from fastapi import FastAPI, HTTPException

app = FastAPI()
logging.config.fileConfig("./app/uvicorn_logging.ini")

@app.get("/")
def handle():
    return "hello"

Overwriting logging_files/app.py

Now let’s try a few requests to this api and see what’s written to our log file.

%%bash
curl -s localhost:8000/
curl -s localhost:8000/
cat logging_files/uvicorn.log

"hello""hello"2024-05-07 11:40:11 - INFO - Started server process [8]
2024-05-07 11:40:11 - INFO - Waiting for application startup.
2024-05-07 11:40:11 - INFO - Application startup complete.
2024-05-07 11:40:17 - INFO - 172.17.0.1:45930 - "GET / HTTP/1.1" 200
2024-05-07 11:40:17 - INFO - 172.17.0.1:45946 - "GET / HTTP/1.1" 200

As you can see, all the logs that uvicorn used to print to the terminal are now on the file.

Contents