FastAPI application processing new requests before sending back previous request's response

[andresbannuraschultz]

First Check

• I added a very descriptive title here.
• I used the GitHub search to find a similar question 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.

Commit to Help

• I commit to help with one of those options 👆

Example Code

from time import sleep

from anyio import CapacityLimiter
from anyio.lowlevel import RunVar
from fastapi import FastAPI

app = FastAPI()

@app.get("/")
def ping() -> str:
    print("start ping")
    sleep(5)
    print("finish ping")
    return "pong!"

@app.on_event("startup")
def startup():
    print("startup")
    RunVar("_default_thread_limiter").set(CapacityLimiter(1))

Description

I'm playing around with FastAPI to understand better how sync and async endpoints work. I've read about Uvicorn's event loop, about the ThreadPool used to handle sync endpoints, and various other related topics.

I came across this method for changing the ThreadPool size, and when running some "experiments" I found some unexpected behavior.

When changing the ThreadPool size to 1 thread, I see that only one request is processed concurrently (expected), BUT the corresponding response is not delivered to the client right away. What do I mean by this? Check these logs (they were produced by triggering 3 simultaneous requests to the same endpoint):

2023-07-13 12:56:27 start ping
2023-07-13 12:56:32 finish ping
2023-07-13 12:56:32 start ping
2023-07-13 12:56:37 finish ping
2023-07-13 12:56:37 start ping
2023-07-13 12:56:42 finish ping
2023-07-13 12:56:42 INFO:     172.18.0.1:49094 - "GET / HTTP/1.1" 200 OK
2023-07-13 12:56:42 INFO:     172.18.0.1:46612 - "GET / HTTP/1.1" 200 OK
2023-07-13 12:56:42 INFO:     172.18.0.1:49114 - "GET / HTTP/1.1" 200 OK

Note: it's not only about the logs, I can also see in my client (e.g. browser, Postman, etc.) that the first response is not received until all requests are processed.

Consistent behavior is seen when the ThreadPool size is increased to 2 or 3 threads. For instance, these are the logs when running the experiment with 2 threads and making 3 simultaneous requests:

2023-07-13 12:59:04 start ping
2023-07-13 12:59:06 start ping
2023-07-13 12:59:09 finish ping
2023-07-13 12:59:09 start ping
2023-07-13 12:59:11 finish ping
2023-07-13 12:59:11 INFO:     172.18.0.1:43632 - "GET / HTTP/1.1" 200 OK
2023-07-13 12:59:11 INFO:     172.18.0.1:50226 - "GET / HTTP/1.1" 200 OK
2023-07-13 12:59:14 finish ping
2023-07-13 12:59:14 INFO:     172.18.0.1:50234 - "GET / HTTP/1.1" 200 OK

In this last example you can see how both the first and second request are handled immediately. But when the first request processing finishes, the response is not sent right away. Instead, the handling of the third request starts. Only when the second request processing finishes, both the first and second response are sent back to the client.

I haven't been able to find the piece of code that's in charge of this logic. But from the outside it seems that Uvicorn, in order to send the response back to the client, requires a new thread (not the same in which the response was "calculated"). If so, maybe this issue is not related to FastAPI, but to Uvicorn, and apologies for wasting your time (although I'm more than happy to see what you folks think about this behavior).

Let me know if I can provide any further details that could be useful!

Operating System

Linux

Operating System Details

Running on Docker container (shouldn't be related to this though).

FastAPI Version

0.95.1

Python Version

3.11

Additional Context

No response

[methane]

Calling one GET / makes two run_in_threadpool() calls:

1. Calling endpoint (e.g. ping() in your example)
2. Calling validator (here)

Explaining your first example:

1. GET / -> run_in_threadpool(ping) -> sleep(5)
2. GET / -> run_in_threadpool(ping) (waiting)
3. GET / -> run_in_threadpool(ping) (waiting)
4. (1) finish -> run_in_threadpool(field_validate) (waiting)
5. (2) start -> sleep(5) -> finish -> run_in_threadpool(field_validate) (waiting)
6. (3) start -> sleep(5) -> finish -> run_in_threadpool(field_validate) (waiting)
7. (4) start -> finish -> send response
8. (5) start -> finish -> send response
9. (6) start -> finish -> send response

[Pitirus]

Hi,
Is there a way to force Fastapi to send the response before starting to handle the subsequent request?

[YuriiMotov]

I think the only way is not to set the ThreadPool size to small number. By default ThreadPool size is 40 and you shouldn't experience mentioned problem.
Also, you will not experience this problem if your endpoints are defined with async def (but their code should be async (non-blocking), of course)

[methane]

You can return Response/JSONResponse directly from path operation function.
field.validate() won't be called for the response object.

return Response("pong!")