[QUESTION] How to do logging in a FastApi container, any logging does not appear

[PunkDork21]

Description
I have another project that utilizes fast api using gunicorn running uvicorn workers and supervisor to keep the api up. Recently I came across the issue that none of my logs from files that are not the fast api app are coming through. Initially I tried making an adhoc script to see if it works as well as changing the levels of the logging. I only had success if I set the logging to be at the DEBUG level.

I put together another small project to test out if I would run into this problem with a clean slate and I still couldn't get logging working with a standard

import logging

log = logging.getLogger(__name__)
log.setLevel(logging.INFO)
log.info('help!')

Other steps I took was chmod-ing the /var/log/ directory in case it was a permissions issue but I had no luck. Has anyone else ran into this or have recommendations on how they implemented logging?

Additional context
For context I put up the testing repo here: https://github.com/PunkDork21/fastapi-git-test
Testing it would be like:

docker-compose up -d
docker exec -it git-test_web_1 bash
python3 ./appy.py

The most of the files are similar to what I have in my real project

[slhck]

I have a similar issue. Using this image, I don't see any FastAPI logs on STDOUT in Docker Compose.

The app is something like this:

from fastapi.logger import logger
…
logger.info("Booted up")

if __name__ == "__main__":
    import uvicorn

    uvicorn.run("main:app", host="0.0.0.0", port=3002, reload=True, debug=True)

When I run it with python3 app/main.py, I see a quite detailed log:

INFO: Uvicorn running on http://0.0.0.0:3002 (Press CTRL+C to quit)
INFO: Started reloader process [99565]
INFO: Booted up
INFO: Started server process [99581]
INFO: Waiting for application startup.
INFO: Application startup complete.

But when I run the app in Docker Compose with LOG_LEVEL=debug set in the environment, and using the start_reload.sh entrypoint, I only see:

INFO: Uvicorn running on http://0.0.0.0:80 (Press CTRL+C to quit)
INFO: Started reloader process [1]
INFO: Started server process [9]
INFO: Waiting for application startup.
DEBUG: None - ASGI [1] Started
DEBUG: None - ASGI [1] Sent {'type': 'lifespan.startup'}
DEBUG: None - ASGI [1] Received {'type': 'lifespan.startup.complete'}

[slhck]

Umair, I'm not sure if that is the same issue. When a Docker container writes to STDOUT and is running in the background (that is, detached), you can only see that via logs.

[JCHHeilmann]

Any news on this issue? I'm having the same problem and can't really find a solution anywhere.
When using the same setup as @slhck warning and error logs get through, but nothing below that And they are also not formatted like the other logs.
So logger.warning("Connected - warning") gets logged out as Connected - warning instead of something like [2020-03-27 17:17:45 +0000] [9] [WARNING] Connected - warning.

[tyler46]

@JCHHeilmann have you had a look on this issue?

[JCHHeilmann]

@tyler46 yes , and I've just tried it that way again. The info log doesn't show up without setting the LOG_LEVEL to debug. But the default is info, so it should. Or am I missing something?

[slhck]

I finally solved it!

First, make sure you set the environment variable LOG_LEVEL to debug, e.g. in your Docker-Compose file.

Now in your actual FastAPI app, add this code below the imports:

from fastapi.logger import logger
# ... other imports
import logging

gunicorn_logger = logging.getLogger('gunicorn.error')
logger.handlers = gunicorn_logger.handlers
if __name__ != "main":
    logger.setLevel(gunicorn_logger.level)
else:
    logger.setLevel(logging.DEBUG)

This way, if your app is loaded via gunicorn, you can tell the logger to use gunicorn's log level instead of the default one. Because if gunicorn loads your app, FastAPI does not know about the environment variable directly; you will have to manually override the log level.

The else branch is for when you run the app directly, in which case I assume debug logging will be required.

I tested this with the version where the command /start-reload.sh is specified in the Docker-Compose config, as well as the one where it is left out, and of course running the app directly.

[slhck]

PS: I got this idea from this blog post: https://medium.com/@trstringer/logging-flask-and-gunicorn-the-manageable-way-2e6f0b8beb2f

[janheindejong]

Hmm... I'm having a similar problem, and can't really figure out how to deal with this.

This is my script:

import logging

from fastapi import FastAPI

app = FastAPI()
logger = logging.getLogger("gunicorn.error")

@app.get("/")
async def root():
    logger.info("Hello!")
    return "Hello, world!"

Running this directly with the following command:

uvicorn main:app

Gives the following output:

INFO:     Uvicorn running on http://127.0.0.1:8000 (Press CTRL+C to quit)
INFO:     Started reloader process [21232]
INFO:     Started server process [12508]
INFO:     Waiting for application startup.
INFO:     Application startup complete.
INFO:     Hello!
INFO:     127.0.0.1:51701 - "GET / HTTP/1.1" 200
INFO:     127.0.0.1:51760 - "GET /123 HTTP/1.1" 404

Running it in the tiangolo/uvicorn-gunicorn-fastapi:python3.7 container gives the following output.

[2020-04-13 14:14:31 +0000] [1] [INFO] Starting gunicorn 20.0.4
[2020-04-13 14:14:31 +0000] [1] [INFO] Listening at: http://0.0.0.0:80 (1)
[2020-04-13 14:14:31 +0000] [1] [INFO] Using worker: uvicorn.workers.UvicornWorker
[2020-04-13 14:14:31 +0000] [8] [INFO] Booting worker with pid: 8
[2020-04-13 14:14:31 +0000] [9] [INFO] Booting worker with pid: 9
[2020-04-13 14:14:31 +0000] [8] [INFO] Started server process [8]
[2020-04-13 14:14:31 +0000] [8] [INFO] Waiting for application startup.
[2020-04-13 14:14:31 +0000] [8] [INFO] Application startup complete.
[2020-04-13 14:14:31 +0000] [9] [INFO] Started server process [9]
[2020-04-13 14:14:31 +0000] [9] [INFO] Waiting for application startup.
[2020-04-13 14:14:31 +0000] [9] [INFO] Application startup complete.
[2020-04-13 14:14:40 +0000] [9] [INFO] Hello!

I'm missing the actual HTTP requests in this case. Don't know if this is a big deal, not very experienced with building web-services yet. Is there a particular reason for not showing the HTTP requests in the console output?

[slhck]

@janheindejong You have not set the logging handler (logger.handlers = gunicorn_logger.handlers). Does that fix the issue?

[janheindejong]

Hmm... am I not using the gunicorn logger? This line basically makes the logger variable point to the gunicorn one, right?

logger = logging.getLogger("gunicorn.error")

It's not that I'm not getting any output from the logger (see the Hello! line). It's just that the HTTP requests are not shown, which they are if I run the app outside the container.

[slhck]

Well, if you set logger to be the gunicorn logger, you can pass your info logs through it, and they will appear. However, FastAPI itself will not know about that and still sends its (HTTP header) logs to its own logger. That means you have to tell FastAPI to use the gunicorn logger handlers. Please try adding that line and see if it works.

[janheindejong]

I've tried adding the gunicorn handlers and level to the fastapi_logger, but that didn't work (see code below).

from fastapi import FastAPI
from fastapi.logger import logger as fastapi_logger

app = FastAPI()
logger = logging.getLogger("gunicorn.error")
fastapi_logger.handlers = logger.handlers
fastapi_logger.setLevel(logger.level)


@app.get("/")
async def root():
    logger.info("Hello!")
    return "Hello, world!"

Note that the Hello! log does get shown.

[slhck]

Hm, do you need the explicit import of fastapi.logger? I thought it worked without that — at least it did for my example. To be honest, I am not sure how this is all supposed to work internally. I just fumbled around with it until it worked. Perhaps you can try using my setup? I set the handlers differently.

[janheindejong]

Hmm... yeah I'm afraid that doesn't work. There's no instance of logger yet if I use your example. How did you create the instance?

[slhck]

That would be:

from fastapi.logger import logger

Sorry for missing that.

[janheindejong]

Ah yes... well... if I use your code, and if I use `logger` in my code, it does indeed work. The problem is that I'm still not seeing the FastAPI logger output (e.g. GET / HTTP/1.1 200).

…

On Tue, Apr 14, 2020 at 2:26 PM Werner Robitza ***@***.***> wrote: That would be: from fastapi.logger import logger Sorry for missing that. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#19 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AHHINZZC65JQW4LYZ547F4DRMRJAPANCNFSM4JEOLYQQ> .

[itaymining]

i also have this problem.. any new?

[slhck]

@itaymining Have you tried my solution from above?

[itaymining]

Yes, but it won't show the 'HTTP-GET/POST" from fastapi routes...
it will only logs i put inside routes. but not native fastapi logs...

[HedgeShot]

I got the same problem occurring since yesterday. Before that, I could see everything in the logs (routes called, response code etc). Now i only see print() after I do some change in the code & the app auto-reloads... I don't even see errors on "internal server error" when calling a broken route. Very strange!

EDIT: I was import "logging" module to use on a few endpoint & i guess the config was messing with the fastapi logger. Removing this fixed my issue.

[JCHHeilmann]

I'm also still having this issue. I've stopped using this docker image as a result.

Actually it might be an issue with uvicorn. I have build my own minimal "start fast-api with uvicorn" docker image and it had the same problem.

[bcb]

I'm not using this repo, but adding this to the gunicorn command worked for me:

--access-logfile -

[janheindejong]

I also think it is a gunicorn thing... I also posted it here:
fastapi/fastapi#1268

[jacob-vincent]

I've struggled with this for the past few days as well, and only just figured it out. The HTTP request info is stored in the uvicorn.access logs. In order to see that information when running uvicorn via gunicorn (lots of unicorns here!), you'll need the following snippet in your main.py

import logging
from fastapi.logger import logger as fastapi_logger

gunicorn_error_logger = logging.getLogger("gunicorn.error")
gunicorn_logger = logging.getLogger("gunicorn")
uvicorn_access_logger = logging.getLogger("uvicorn.access")
uvicorn_access_logger.handlers = gunicorn_error_logger.handlers

fastapi_logger.handlers = gunicorn_error_logger.handlers

if __name__ != "__main__":
    fastapi_logger.setLevel(gunicorn_logger.level)
else:
    fastapi_logger.setLevel(logging.DEBUG)

This will allow the gunicorn.error logger to handle the uvicorn.access logger, thus allowing the HTTP request information to come through. You don't even need to add --access-log - in the gunicorn command (but thank you for the suggestion, @bcb!) Big, huge thanks to @slhck and @bcb for pointing me in this direction. I hope that this helps others!

[itaymining]

I've struggled with this for the past few days as well, and only just figured it out. The HTTP request info is stored in the uvicorn.access logs. In order to see that information when running uvicorn via gunicorn (lots of unicorns here!), you'll need the following snippet in your main.py

import logging
from fastapi.logger import logger as fastapi_logger

gunicorn_error_logger = logging.getLogger("gunicorn.error")
gunicorn_logger = logging.getLogger("gunicorn")
uvicorn_access_logger = logging.getLogger("uvicorn.access")
uvicorn_access_logger.handlers = gunicorn_error_logger.handlers

fastapi_logger.handlers = gunicorn_error_logger.handlers

if __name__ != "__main__":
    fastapi_logger.setLevel(gunicorn_logger.level)
else:
    fastapi_logger.setLevel(logging.DEBUG)

This will allow the gunicorn.error logger to handle the uvicorn.access logger, thus allowing the HTTP request information to come through. You don't even need to add --access-log - in the gunicorn command (but thank you for the suggestion, @bcb!) Big, huge thanks to @slhck and @bcb for pointing me in this direction. I hope that this helps others!

Thanks allot! it works for me!

[bcb]

Above solution doesn't work for me.

Also this solution ties the application code too closely to the deployment method.

We shouldn't be referencing gunicorn/uvicorn in the code.

[gsph]

fastapi/fastapi#1276 (comment)

[JHBalaji]

@bcb Maybe this implementation
And there is this.

[ms042087]

The above solution does not work for me. Anyone has other solution? Thanks!

docker-compose.yml

version: "3"
services:
  api:
    build:
      context: ./
      dockerfile: Dockerfile
    environment:
      - DEBUG = 1
      - PYTHONUNBUFFERED = 1
      - LOGLEVEL = DEBUG
    image: result/latest

main.py

from fastapi import FastAPI
from fastapi.logger import logger
import logging

gunicorn_logger = logging.getLogger('gunicorn.error')
logger.handlers = gunicorn_logger.handlers
if __name__ != "main":
    logger.setLevel(gunicorn_logger.level)
else:
    logger.setLevel(logging.DEBUG)

app = FastAPI()
@app.get("/")
def dashboard():
        return{"Dashboard":"Homepage"}

[tedivm]

The problem with the solution going around here is that it breaks logging when gunicorn isn't being used. It also doesn't affect the root handler, which is what a lot of modules are going to be using.

Here's the version I use which tries to resolve those issues as well-

import logging
from fastapi.logger import logger as fastapi_logger

if "gunicorn" in os.environ.get("SERVER_SOFTWARE", ""):
    '''
    When running with gunicorn the log handlers get suppressed instead of
    passed along to the container manager. This forces the gunicorn handlers
    to be used throughout the project.
    '''

    gunicorn_logger = logging.getLogger("gunicorn")
    log_level = gunicorn_logger.level

    root_logger = logging.getLogger()
    gunicorn_error_logger = logging.getLogger("gunicorn.error")
    uvicorn_access_logger = logging.getLogger("uvicorn.access")

    # Use gunicorn error handlers for root, uvicorn, and fastapi loggers
    root_logger.handlers = gunicorn_error_logger.handlers
    uvicorn_access_logger.handlers = gunicorn_error_logger.handlers
    fastapi_logger.handlers = gunicorn_error_logger.handlers

    # Pass on logging levels for root, uvicorn, and fastapi loggers
    root_logger.setLevel(log_level)
    uvicorn_access_logger.setLevel(log_level)
    fastapi_logger.setLevel(log_level)

[arocketman]

You can also take advantage of yaml configuration to propagate logs to the root handler. Basically use the root handler along with a fileHandler and a streamHandler, then propagate the uvicorn one (I propagate the error, but you can also propagate the access):

version: 1
disable_existing_loggers: false

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

handlers:
  console:
    class: logging.StreamHandler
    formatter: standard
    level: INFO
    stream: ext://sys.stdout

  file:
    class: logging.handlers.WatchedFileHandler
    formatter: standard
    filename: mylog.log
    level: INFO


loggers:
  uvicorn:
    error:
      propagate: true

root:
  level: INFO
  handlers: [console, file]
  propagate: no

Then at app startup:

logging.config.dictConfig('config.yml')

[FrancescoSaverioZuppichini]

any easy way to do it?

[pawamoy]

Use this script to run your app in a Docker container?

[rookiecj]

You can also take advantage of yaml configuration to propagate logs to the root handler. Basically use the root handler along with a fileHandler and a streamHandler, then propagate the uvicorn one (I propagate the error, but you can also propagate the access):

version: 1
disable_existing_loggers: false

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

handlers:
  console:
    class: logging.StreamHandler
    formatter: standard
    level: INFO
    stream: ext://sys.stdout

  file:
    class: logging.handlers.WatchedFileHandler
    formatter: standard
    filename: mylog.log
    level: INFO


loggers:
  uvicorn:
    error:
      propagate: true

root:
  level: INFO
  handlers: [console, file]
  propagate: no

Then at app startup:

logging.config.dictConfig('config.yml')

small modification to dictConfig

# pip install PyYAML
import yaml

with open('config.yml') as f:
    config = yaml.load(f, Loader=yaml.FullLoader)
    logging.config.dictConfig(config)

[perklet]

OK, I found that most of the solutions here do not work for me if unmodified, but I figured out what works for me, here it is:

if "gunicorn" in os.environ.get("SERVER_SOFTWARE", ""):
    gunicorn_error_logger = logging.getLogger("gunicorn.error")
    gunicorn_logger = logging.getLogger("gunicorn")

    fastapi_logger.setLevel(gunicorn_logger.level)
    fastapi_logger.handlers = gunicorn_error_logger.handlers
    root_logger.setLevel(gunicorn_logger.level)

    uvicorn_logger = logging.getLogger("uvicorn.access")
    uvicorn_logger.handlers = gunicorn_error_logger.handlers
else:
    # https://github.com/tiangolo/fastapi/issues/2019
    LOG_FORMAT2 = "[%(asctime)s %(process)d:%(threadName)s] %(name)s - %(levelname)s - %(message)s | %(filename)s:%(lineno)d"
    logging.basicConfig(level=logging.INFO, format=LOG_FORMAT2)

This works for both uvicorn standalone and gunicorn with uvicorn workers:

uvicorn app:app --port 3000 --reload --log-level info

gunicorn -w 4 -k uvicorn.workers.UvicornWorker app:app -b 127.0.0.1:3000

[jaytimbadia]

I've struggled with this for the past few days as well, and only just figured it out. The HTTP request info is stored in the uvicorn.access logs. In order to see that information when running uvicorn via gunicorn (lots of unicorns here!), you'll need the following snippet in your main.py

import logging
from fastapi.logger import logger as fastapi_logger

gunicorn_error_logger = logging.getLogger("gunicorn.error")
gunicorn_logger = logging.getLogger("gunicorn")
uvicorn_access_logger = logging.getLogger("uvicorn.access")
uvicorn_access_logger.handlers = gunicorn_error_logger.handlers

fastapi_logger.handlers = gunicorn_error_logger.handlers

if __name__ != "__main__":
    fastapi_logger.setLevel(gunicorn_logger.level)
else:
    fastapi_logger.setLevel(logging.DEBUG)

This will allow the gunicorn.error logger to handle the uvicorn.access logger, thus allowing the HTTP request information to come through. You don't even need to add --access-log - in the gunicorn command (but thank you for the suggestion, @bcb!) Big, huge thanks to @slhck and @bcb for pointing me in this direction. I hope that this helps others!

Hey Brilliant work.
But how do we get gunicorn log formattted logs which contains request time and request byte length?
Any idea?
Currently its printing in this way.
172.30.16.1:62618 - "GET /docs HTTP/1.1" 200
172.30.16.1:62618 - "GET /openapi.json HTTP/1.1" 200
2021-08-18 15:34:37.893 | INFO | server.routes_v1.mongo_routes:get_hello:92 - hello
2021-08-18 15:34:37.893 | DEBUG | server.routes_v1.mongo_routes:get_hello:93 - hello
2021-08-18 15:34:37.894 | ERROR | server.routes_v1.mongo_routes:get_hello:94 - hello
2021-08-18 15:34:37.894 | WARNING | server.routes_v1.mongo_routes:get_hello:95 - hello
172.30.16.1:62618 - "GET /v1/api/hello HTTP/1.1" 200

I want also request time and request bytes length which gunicorn provides.

My gunicorn conf file.
workers = web_concurrency
bind = use_bind
loglevel = 'info'

errorlog = "gunicorn_error.log"

syslog = True

accesslog = "-"
access_log_format = '%(h)s %(t)s'
daemon=False

options = {
"bind": use_bind,
"workers": web_concurrency,
"errorlog": "error.log",
"worker_class": "uvicorn.workers.UvicornWorker",
}

please help!!

[alencodes]

One shall make use of logging configuration via YAML
https://gist.github.com/alencodes/37d590e98db7c7d2dc46cc24e708ea38

import logging
logger = logging.getLogger('CORE')
logger.info('CORE started!')

2021-09-23 13:40:21,464 INFO     CORE            CORE started!
2021-09-23 13:40:21,466 INFO     uvicorn.error   Started server process [11064]
2021-09-23 13:40:21,466 INFO     uvicorn.error   Waiting for application startup.
2021-09-23 13:40:21,467 INFO     uvicorn.error   Application startup complete.
2021-09-23 13:40:21,468 INFO     uvicorn.error   Uvicorn running on http://127.0.0.1:8000 (Press CTRL+C to quit)

[dvmaster95]

You can also take advantage of yaml configuration to propagate logs to the root handler. Basically use the root handler along with a fileHandler and a streamHandler, then propagate the uvicorn one (I propagate the error, but you can also propagate the access):

version: 1
disable_existing_loggers: false

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

handlers:
  console:
    class: logging.StreamHandler
    formatter: standard
    level: INFO
    stream: ext://sys.stdout

  file:
    class: logging.handlers.WatchedFileHandler
    formatter: standard
    filename: mylog.log
    level: INFO


loggers:
  uvicorn:
    error:
      propagate: true

root:
  level: INFO
  handlers: [console, file]
  propagate: no

Then at app startup:
logging.config.dictConfig('config.yml')

small modification to dictConfig

# pip install PyYAML
import yaml

with open('config.yml') as f:
    config = yaml.load(f, Loader=yaml.FullLoader)
    logging.config.dictConfig(config)

Sorry if I'm posting in this issue after several months, but using this approach now I can properly see all the logs in the console, however there is no mylog.log in my folder. I'm running this container in a VM with ubuntu, is it possible that something else could be blocking the creation of this log file?

[dvmaster95]

You can also take advantage of yaml configuration to propagate logs to the root handler. Basically use the root handler along with a fileHandler and a streamHandler, then propagate the uvicorn one (I propagate the error, but you can also propagate the access):

version: 1
disable_existing_loggers: false

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

handlers:
  console:
    class: logging.StreamHandler
    formatter: standard
    level: INFO
    stream: ext://sys.stdout

  file:
    class: logging.handlers.WatchedFileHandler
    formatter: standard
    filename: mylog.log
    level: INFO


loggers:
  uvicorn:
    error:
      propagate: true

root:
  level: INFO
  handlers: [console, file]
  propagate: no

Then at app startup:
logging.config.dictConfig('config.yml')

small modification to dictConfig

# pip install PyYAML
import yaml

with open('config.yml') as f:
    config = yaml.load(f, Loader=yaml.FullLoader)
    logging.config.dictConfig(config)

Sorry if I'm posting in this issue after several months, but using this approach now I can properly see all the logs in the console, however there is no mylog.log in my folder. I'm running this container in a VM with ubuntu, is it possible that something else could be blocking the creation of this log file?

This might seem super obvious to somebody else, but I didn't find the specific mylog.log file, however, I did find the information I needed in the docker logs located at /var/lib/docker/containers.

[FelipeNFL]

I've struggled with this for the past few days as well, and only just figured it out. The HTTP request info is stored in the uvicorn.access logs. In order to see that information when running uvicorn via gunicorn (lots of unicorns here!), you'll need the following snippet in your main.py

import logging
from fastapi.logger import logger as fastapi_logger

gunicorn_error_logger = logging.getLogger("gunicorn.error")
gunicorn_logger = logging.getLogger("gunicorn")
uvicorn_access_logger = logging.getLogger("uvicorn.access")
uvicorn_access_logger.handlers = gunicorn_error_logger.handlers

fastapi_logger.handlers = gunicorn_error_logger.handlers

if __name__ != "__main__":
    fastapi_logger.setLevel(gunicorn_logger.level)
else:
    fastapi_logger.setLevel(logging.DEBUG)

This will allow the gunicorn.error logger to handle the uvicorn.access logger, thus allowing the HTTP request information to come through. You don't even need to add --access-log - in the gunicorn command (but thank you for the suggestion, @bcb!) Big, huge thanks to @slhck and @bcb for pointing me in this direction. I hope that this helps others!

It worked! Thank you!

[tiangolo]

Thanks everyone for the discussion and help here! 🙇

Some of these things were solved in some recent(ish) Uvicorn versions. And for other cases the tricks in the comments here might be what you need.

If you are still having problems, please create a new issue. If @PunkDork21's problem was solved, you can close the issue now.

Also, just a reminder, you probably don't need this Docker image anymore: https://github.com/tiangolo/uvicorn-gunicorn-fastapi-docker#-warning-you-probably-dont-need-this-docker-image

Sorry for the long delay! 🙈 I wanted to personally address each issue and they piled up through time, but now I'm checking each one in order.

[tedivm]

That said, if you're looking for a uvicorn container image that's always up to date, supports multiple versions of python, and also supports ARM then you should check out the multi-py uvicorn image.

[github-actions]

Assuming the original issue was solved, it will be automatically closed now. But feel free to add more comments or create new issues.

[ethanopp]

I've struggled with this for the past few days as well, and only just figured it out. The HTTP request info is stored in the uvicorn.access logs. In order to see that information when running uvicorn via gunicorn (lots of unicorns here!), you'll need the following snippet in your main.py

import logging
from fastapi.logger import logger as fastapi_logger

gunicorn_error_logger = logging.getLogger("gunicorn.error")
gunicorn_logger = logging.getLogger("gunicorn")
uvicorn_access_logger = logging.getLogger("uvicorn.access")
uvicorn_access_logger.handlers = gunicorn_error_logger.handlers

fastapi_logger.handlers = gunicorn_error_logger.handlers

if __name__ != "__main__":
    fastapi_logger.setLevel(gunicorn_logger.level)
else:
    fastapi_logger.setLevel(logging.DEBUG)

This will allow the gunicorn.error logger to handle the uvicorn.access logger, thus allowing the HTTP request information to come through. You don't even need to add --access-log - in the gunicorn command (but thank you for the suggestion, @bcb!) Big, huge thanks to @slhck and @bcb for pointing me in this direction. I hope that this helps others!

@jacob-vincent thanks for sharing this. I am struggling getting my log setup working as well and this has got me 90% of the way there. I am facing 1 more issue I was hoping you may be able to shed some light on... Can't seem to get the logs working for tasks that are kicked off via an AsyncIOScheduler()

from fastapi import FastAPI
from models.db import init_db
from routers.portfolio import router as portfolio_router
from routers.balance import router as balance_router
from routers.transaction import router as transaction_router

from idom import component, html
from idom.backend.fastapi import configure
import os
from tasks import manage_portfolio_task, fetch_liquidity_changes
from apscheduler.schedulers.asyncio import AsyncIOScheduler

# Configure logs
import logging
from fastapi.logger import logger as fastapi_logger
gunicorn_error_logger = logging.getLogger("gunicorn.error")
gunicorn_logger = logging.getLogger("gunicorn")
uvicorn_access_logger = logging.getLogger("uvicorn.access")
uvicorn_access_logger.handlers = gunicorn_error_logger.handlers

fastapi_logger.handlers = gunicorn_error_logger.handlers

if __name__ != "__main__":
    fastapi_logger.setLevel(gunicorn_logger.level)
else:
    fastapi_logger.setLevel(logging.DEBUG)

# Configure endpoints
app = FastAPI()
app.include_router(portfolio_router, prefix="/portfolio", tags=["Portfolio"])
app.include_router(balance_router, prefix="/balance", tags=["Balance"])
app.include_router(transaction_router, prefix="/transaction", tags=["Transaction"])

# Setup Scheduler
scheduler = AsyncIOScheduler()
scheduler.add_job(manage_portfolio_task, "interval", seconds=10)
scheduler.add_job(fetch_liquidity_changes, "interval", minutes=5)
scheduler.start()

# Configure DB
@app.on_event("startup")
async def on_startup():
    # Startup db
    await init_db()

# For local dev
if __name__ == "__main__":
    import uvicorn
    uvicorn.run(app, host="0.0.0.0", port=8000)

Have a separate issue open here as well but think its very closely related to this one
#227

[nextmat]

This issue is still pretty popular. It took me a while to figure this out, so in case it helps other folks:

The default setting for Uvicorn access logs is to write them to STDOUT. However, the default setting for Gunicorn access logs is to discard them without writing them anywhere.

On the other hand, the default setting for Gunicorn error logs is to stream to STDERR.

When running Uvicorn as a worker class for Gunicorn, Uvicorn will attach its logs properly to Gunicorn's access and error loggers, but unless you have configured the access log to write somewhere you will never see them. It is easy to be confused by this because the default behaviors for Uvicorn/Gunicorn are opposite so the logs just seem to disappear.

Given all of this if you re-use the handlers from Gunicorn's error logger for your access logs, you will see output, but it will be STDERR output (or wherever the error logger is configured to go). This probably isn't what you want.

Instead configure the Gunicorn access logger location and your uvicorn/app logs should start showing up. If you are trying to get them to show up in your console, use "-" to send them to STDOUT.

[rwinslow]

My team just switched to hypercorn from gunicorn to get http/2 and ran into a ton of logging issues. Because the documentation isn't great on that project right now and this discussion is still up, I'll put our solution here in case anyone is searching for a solution and comes across this.

Not sure why hypercorn doesn't respect the log config the same way as gunicorn or uvicorn, but it doesn't today, at least when used in conjunction with fastapi. We needed to apply the config in the logging module before other imports to make sure they all inherited the same settings. This worked for us both at the CLI and in docker.

Here are our files and what we did:

Put this somewhere accessible to whichever file is your main.py or equivalent that instantiates your app.

log_config.json

{
  "version": 1,
  "disable_existing_loggers": false,
  "formatters": {
    "standard": {
      "format": "%(asctime)s - %(name)s - %(levelname)s - %(message)s"
    },
    "minimal": {
      "format": "%(message)s"
    }
  },
  "handlers": {
    "console": {
      "level": "INFO",
      "class": "logging.StreamHandler",
      "formatter": "standard",
      "stream": "ext://sys.stdout"
    },
    "hypercorn": {
      "level": "INFO",
      "class": "logging.StreamHandler",
      "formatter": "minimal",
      "stream": "ext://sys.stdout"
    }
  },
  "root": {
    "handlers": [
      "console"
    ],
    "level": "INFO"
  },
  "loggers": {
    "": {
      "handlers": [
        "console"
      ],
      "level": "INFO",
      "propagate": false
    },
    "hypercorn.error": {
      "handlers": [
        "hypercorn"
      ],
      "level": "INFO",
      "propagate": false
    },
    "hypercorn.access": {
      "handlers": [
        "hypercorn"
      ],
      "level": "INFO",
      "propagate": false
    }
  }
}

Here's the most important part

main.py

import json
import logging
import logging.config
import os

# Need to setup loggers before importing other modules that may use loggers
# Use whatever path you need to grab the log_config.json file
with open(os.path.join(os.path.dirname(__file__), "log_config.json")) as f:
    logging.config.dictConfig(json.load(f))

# All other imports go below here

_LOGGER.getLogger(__name__)

To run with Hypercorn

hypercorn src.main:app --bind 0.0.0.0:${PORT} --workers 4 --access-logfile - --error-logfile - --worker-class trio

[dbrnz]

@rwinslow see here for what works in Hypercorn.