Critical worker timeout appearing once in a while in production

[MrNaif2018]

First check

• I added a very descriptive title to this issue.
• I used the GitHub search to find a similar issue and didn't find it.
• I searched the FastAPI documentation, with the integrated search.
• I already searched in Google "How to X in FastAPI" and didn't find any information.
• I already read and followed all the tutorial in the docs and didn't find an answer.
• I already checked if it is not related to FastAPI but to Pydantic.
• I already checked if it is not related to FastAPI but to Swagger UI.
• I already checked if it is not related to FastAPI but to ReDoc.
• After submitting this, I commit to one of:
  • Read open issues with questions until I find 2 issues where I can help someone and add a comment to help there.
  • I already hit the "watch" button in this repository to receive notifications and I commit to help at least 2 people that ask questions in the future.
  • Implement a Pull Request for a confirmed bug.

Example

I am not sure if I am able to create a minimal example, see description below.

Description

I have been using FastAPI for almost a year now without almost any issues, but I met one issue which is quite hard to reproduce and I might need your help.

My backend (simplified), consists of two parts: the API, and the worker. The API is run by gunicorn, and the worker is run separately, to avoid creating duplicate instances of background tasks. They are communicating between each other via redis.
What I have is, a background task that should mark an object (invoice) as expired after certain time.
What I did is an async function, that just does asyncio.sleep, and after that it marks invoice as expired in the database.
When invoice is created (from the API, via one of the workers gunicorn is serving), an asyncio task is created to mark invoice expired later.
Also, the background worker on startup checks pending invoices if they have expired.
Seems to be working fine even after server restarts.

But in very cases it doesn't work, I have checked server logs, and saw a few entries with "[CRITICAL] Worker timeout"
So as far as I understand, from time to time the workers time out and get restarted, so all started async tasks are lost.

It happens quite rarely, for now 3 times: on January 4th, 10th and 17th, and every time multiple workers get restarted or get restarted multiple times.
All my functions are async, and I am not sure what exactly might cause the timeout if all the long-running functions are delegated to the worker.

Attaching screenshots, and all the code is available at github too.

I am sorry that I am unable to provide a simple example, because the project is complex, and I think that I don't have any long-running tasks in the gunicorn process (proper distribution of tasks, this system has been working great on many systems, including the demo which is running without any issues except for this for 1 month already).

I think that the issue might be just my gunicorn configuration, which is the default one almost.

I understand that it might be hard to investigate the issue, so I am ready to provide all needed details and answer all the following questions in detail. I was directed here from discord.

Environment

• OS: Linux; Docker environment with docker-compose; Custom setup:
  backend component
  worker component
  Dockerfile
• FastAPI Version: 0.63.0
• Python version: 3.6.12

Additional context

The function running as an async task:

Server logs:

How the task is started:

Gunicorn config:

import multiprocessing

bind = "0.0.0.0:8000"
workers = multiprocessing.cpu_count() * 2 + 1
worker_class = "uvicorn.workers.UvicornWorker"

Backend startup script:

#!/usr/bin/env sh
set -ex
alembic upgrade head
gunicorn -c gunicorn.conf.py main:app

Entrypoint

Repository

[raphaelauv]

If you don't have a fastAPI question or BUG report , then I don't see the purpose of your issue ( you can probably close your issue , no one can debug your code )

But I can give you an advise :

I see that you do an asyncio.sleep in your code

It do not sleep for exactly the time you ask, it sleep at minimum the time you ask.

so it's not surprising that you could sleep more than the timeout of your gunicorn worker conf

If you have a lot of tasks taking an amount of time, the task that is doing an asyncio.sleep can wait a long time before getting back the execution from the async loop.

example :

import asyncio


async def test_asyncio_slepp():
    async def a():
        while True:
            import time

            start = time.time()
            print("sleep sync")
            time.sleep(20)
            end = time.time()
            print("sync time =" + str(end - start))
            await asyncio.sleep(1)  # to release to loop

    async def b():
        while True:
            import time

            start = time.time()
            print("sleep async")
            await asyncio.sleep(10)
            end = time.time()
            print("async time =" + str(end - start))

    rst_b = asyncio.create_task(b())
    rst_a = await asyncio.create_task(a())


async def main():
    await test_asyncio_slepp()


if __name__ == '__main__':
    asyncio.run(main())

give :

sleep async
sleep sync
sync time =20.018694400787354
async time =20.01886749267578
....

[MrNaif2018]

Hi! Thank you for your reply.
I also think that this issue is not for github, that's why I asked in discord, but I was directed there so that fastapi experts could help, but noone could (:
Hmm, maybe it is indeed the asyncio.sleep, but if it is created as an async task (create_task or ensure_future), will gunicorn still think that the worker is processing a request?
Anyway, recently I've moved all the event handling, even those long-running asyncio.sleeps to a separate process, and the gunicorn workers just send a command to redis (pub/sub).

Why was I asking is, maybe there is something in my gunicorn configuration, which is fairly simple.
There aren't many guides on how to deploy properly in production (the general advice is to use gunicorn with uvicorn worker, which I use). I am building custom docker images instead of the fastapi-gunicorn-docker, as my project is complex and we are aiming for minimal docker image size.

I will probably leave this issue open for some time, as maybe this issue arises once again, and maybe someone could suggest some improvements to the default gunicorn config.
(By the way, the issue is labeled with special question label, so it is indeed a question)

[raphaelauv]

will gunicorn still think that the worker is processing a request?

Gunicorn don't give a damn about what is doing fastapi, It wait for timeout, nothing more.

There aren't many guides on how to deploy properly in production

Wrong -> the doc https://www.uvicorn.org/deployment/ and https://docs.gunicorn.org/en/stable/settings.html#timeout

[MrNaif2018]

Gunicorn don't give a damn about what is doing fastapi, It wait for timeout, nothing more.

But then why is creating such tasks a problem? I remember before, I was needed to execute some long-running action, so I used BackgroundTasks. Now all the background actions are all in a separate process. But I though that if I asyncio.ensure_future the coroutine, it will not make the gunicorn think a timeout has happened. Should BackgroundTasks or a separate process be used for that too? (What I thought is, when creating the async task, it's scheduled somewhere in the event loop, and the request processing function returns a response and finishes, and the asyncio task runs somewhere later, so not interrupting anything)
My action I need to execute is not long-running, it is more like long-sleeping. It just needs to be executed some time after the task was created, so it sleeps till the actual time it needs to execute.

Wrong -> the doc https://www.uvicorn.org/deployment/ and https://docs.gunicorn.org/en/stable/settings.html#timeout

Well, actually right. I've seen this documentation a lot of times. It only documents possible options, which is good too. But what I mean is, the recommended settings for gunicorn+uvicorn+fastapi app. For example, the docs says that timeout of 30 seconds is enough, but in general gunicorn documentation is mostly related to it's sync workers and not ASGI in general.

[ycd]

@MrNaif2018 can you add threads = workers to your gunicorn config and test it again?

[MrNaif2018]

I can. But the problem is, this issue arises once in a while (5 days, a week, or even more sometimes, etc.). I haven't found any way to reproduce it faster (might it be the memory leak?)
Should I deploy this modified version, or it might indeed be the memory leak?
For now it uses an evenly-spreaded amount of RAM (1.1%, which is 87,736 MB per each worker)

[MrNaif2018]

I have been checking server logs for 20 days, and no issues so far.
Looks like that by delegating all tasks (not only background tasks which could hang on network request or something, but even sleeping asyncio tasks) to another process (worker), timeouts aren't happening anymore. Closing this, will re-open if the issue appears again. Thanks everyone for your help!

For those wondering how is the delegation event system done (via redis pub/sub), you can check it there.

[tiangolo]

Thanks for the help here @raphaelauv and @ycd ! 👏 🙇

I think there's a chance that you're deploying behind Kubernetes or something like that, in that case you probably shouldn't use Gunicorn and instead just use Uvicorn with multiple containers: https://fastapi.tiangolo.com/deployment/docker/

If you are running background tasks that need to do something even slightly complex, that would probably be better run outside, in a background job queue system like RQ, Celery, etc. (not sure if that's what you're doing or not).

Anyway, I imagine you already solved it but wanted to comment for completeness.

Thanks for reporting back and closing the issue @MrNaif2018 👍

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

[MrNaif2018]

Hmm, why shouldn't gunicorn with uvicorn workers be used?
And yeah, I solved it by a separate worker process which follows pub/sub model via redis