How to add timestamp to each request in uvicorn logs?

Question

When I run my FastAPI server using uvicorn:

uvicorn main:app --host 0.0.0.0 --port 8000 --log-level info

The log I get after running the server:

INFO:     Started server process [405098]
INFO:     Waiting for application startup.
INFO:     Connect to database...
INFO:     Successfully connected to the database!
INFO:     Application startup complete.
INFO:     Uvicorn running on http://0.0.0.0:8000 (Press CTRL+C to quit)
INFO:     122.179.31.158:54604 - "GET /api/hello_world?num1=5&num2=10 HTTP/1.1" 200 OK

How do I get the time stamp along with the request logging? Like:

INFO:     "2020-07-16:23:34:78" - 122.179.31.158:54604 - "GET /api/hello_world?num1=5&num2=10 HTTP/1.1" 200 OK

Answer 1

You can use Uvicorn's LOGGING_CONFIG

import uvicorn
from uvicorn.config import LOGGING_CONFIG
from fastapi import FastAPI

app = FastAPI()

def run():
    LOGGING_CONFIG["formatters"]["default"]["fmt"] = "%(asctime)s [%(name)s] %(levelprefix)s %(message)s"
    uvicorn.run(app)

if __name__ == '__main__':
    run()

Which will return uvicorn log with the timestamp

2020-08-20 02:33:53,765 [uvicorn.error] INFO:     Started server process [107131]
2020-08-20 02:33:53,765 [uvicorn.error] INFO:     Waiting for application startup.
2020-08-20 02:33:53,765 [uvicorn.error] INFO:     Application startup complete.
2020-08-20 02:33:53,767 [uvicorn.error] INFO:     Uvicorn running on http://127.0.0.1:8000 (Press CTRL+C to quit)

Answer 2

You can create a dict logger config and initialize the same using dictConfig function in your main application.

#main.py

from logging.config import dictConfig
from config import log_config

from fastapi import FastAPI

dictConfig(log_config.sample_logger)

app = FastAPI()


@app.get("/")
async def root():
    return {"message": "Hello World"}

#config/log_config.py

sample_logger = {
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {
        "access": {
            "()": "uvicorn.logging.AccessFormatter",
            "fmt": '%(levelprefix)s %(asctime)s :: %(client_addr)s - "%(request_line)s" %(status_code)s',
            "use_colors": True
        },
    },
    "handlers": {
        "access": {
            "formatter": "access",
            "class": "logging.StreamHandler",
            "stream": "ext://sys.stdout",
        },
    },
    "loggers": {
        "uvicorn.access": {
            "handlers": ["access"],
            "level": "INFO",
            "propagate": False
        },
    },
}

Answer 3

Combined the answers of @Yagiz Degirmenci and @HappyFace, I got this code.

LOGGING_CONFIG["formatters"]["default"]["fmt"] = "%(asctime)s [%(name)s] %(levelprefix)s %(message)s"
LOGGING_CONFIG["formatters"]["access"][
    "fmt"] = '%(asctime)s [%(name)s] %(levelprefix)s %(client_addr)s - "%(request_line)s" %(status_code)s'

The log likes this:

2021-03-31 18:38:22,728 [uvicorn.error] INFO:     Started server process [21824]
2021-03-31 18:38:22,729 [uvicorn.error] INFO:     Waiting for application startup.
2021-03-31 18:38:22,729 [uvicorn.error] INFO:     Application startup complete.
2021-03-31 18:38:22,729 [uvicorn.error] INFO:     Uvicorn running on http://0.0.0.0:8000 (Press CTRL+C to quit)
2021-03-31 18:38:26,359 [uvicorn.access] INFO:     127.0.0.1:51932 - "POST /limit HTTP/1.1" 200 OK