[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 notifications@github.com 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 https://github.com/tiangolo/uvicorn-gunicorn-fastapi-docker/issues/19#issuecomment-613412781, 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: https://github.com/tiangolo/fastapi/issues/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]

https://github.com/tiangolo/fastapi/issues/1276#issuecomment-615877177

[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"}

[pawamoy]

I wrote a solution here (and the same thing, explained a bit more, in this blog post)

[janheindejong]

Nice, @pawamoy! I also had to do a deep-dive into the inner workings of logger... and like yourself, still have a few unresolved mysteries (why are the gunicorn and uvicorn loggers not children of root?!).

I ended up with the following logging config JSON, that seems to work if you set it in your main.py. Slightly less advanced, but it works...

{ 
    "version": 1, 
    "formatters": {
        "default": { 
            "format": "%(asctime)s - %(process)s - %(name)s - %(levelname)s - %(message)s"
        }
    },
    "handlers": {
        "console": {
            "formatter": "default", 
            "class": "logging.StreamHandler",
            "stream": "ext://sys.stdout", 
            "level": "DEBUG"
            }
    },
    "root": {
            "handlers": ["console"], 
            "level": "DEBUG" 
    }, 
    "loggers": {
        "gunicorn": {
            "propagate": true
        },
        "uvicorn": {
            "propagate": true
        },
        "uvicorn.access": {
            "propagate": true
        }
    }
}

[jseiser]

I wrote a solution here (and the same thing, explained a bit more, in this blog post)

Id love to attempt this, but im not sure where I would actually place this code.

I have

app/__init__.py
app/main.py
app/routers/version.py
app/routes/healthz.py

my main.py just looks like

from fastapi import FastAPI
from .routers import version, healthz

app = FastAPI()

app.include_router(
    version.router, prefix="/version", tags=["version"],
)

I run the code locally from a Dir above app/

❯ poetry shell
Spawning shell within /Users/justin/lugia/.venv
❯ . /Users/justin/lugia/.venv/bin/activate
❯ poetry run uvicorn app.main:app --reload
INFO:     Uvicorn running on http://127.0.0.1:8000 (Press CTRL+C to quit)
INFO:     Started reloader process [21021] using statreload

And my DockerFile I just end with

COPY ./app /app/app

So im not sure how I would integrate all this logging with how the app is currently setup. Because I get a 400 in production for one of these routes, but all I can see in the logs is a generic 400, instead of showing me what is actually happening.

[pawamoy]

So your directory structure is:

repo
  app
    main.py

Then the only line you have to change in run.py (from my blog post) is:

-from my_app.app import app
+from app.main import app

The repo directory must be in the Python path.

For the Dockerfile, it's about the same thing: make sure /app is in the Python path (so Python can find your /app/app package), and simply call python run.py:

# ...
COPY run.py /run.py
CMD ["python", "/run.py"]

[jseiser]

@pawamoy

Ill have to sit and look through this all again, because those changes, break my poetry run, and they break the docker deployment as well. Docker builds, but I can no longer access anything.

Thanks for the guide though.

[adamerose]

So is this a problem with Fastapi or Uvicorn?

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?

The default logs indicate the incorrect log level, see my 2nd image below.

---

logger = logging.getLogger(__name__)
logger.info("info")
logger.warning("warning")
logger.error("error")
logger.error("loglevel="+logging.getLevelName(logger.getEffectiveLevel()))

Local:

Docker:

[fgimian]

I haven't played too much with this image, but I have historically solved the problem like this:

import logging

# Configure the root log level and ensure all logs are sent to Gunicorn's error log.
gunicorn_error_logger = logging.getLogger("gunicorn.error")
# (you could probably just use = instead extend below)
logging.root.handlers.extend(gunicorn_error_logger.handlers)
logging.root.setLevel(gunicorn_error_logger.level)

This will set the all loggers to the same level as you configure in Gunicorn and ensure that all loggers end up in the Gunicorn error logs.

Normally I would place this s a post_fork in the Gunicorn config but you should be able to place it at the start of your application code too.

[albertotb]

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!

I wanted to report that I came across this problem and this solution worked for me. I also wanted to try @pawamoy run.py but I'm not sure how to integrate it with @tiangolo fastapi Docker image.

[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.