Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Returns the file, the event loop may be blocked #2664

Closed
majiang213 opened this issue Aug 9, 2024 · 7 comments
Closed

Returns the file, the event loop may be blocked #2664

majiang213 opened this issue Aug 9, 2024 · 7 comments

Comments

@majiang213
Copy link

Hi, everyone. I have a problem.
When returning a file in high concurrency, the event loop may be blocked. For details, please refer to this discussion

encode/uvicorn#2419
@majiang213
Copy link
Author

Any updates on this issue?

@Kludex
Copy link
Member

Kludex commented Aug 20, 2024

Well, no. You provide an MRE with FastAPI, this is Starlette, and you don't even add the MRE here.

@Kludex
Copy link
Member

Kludex commented Aug 20, 2024

I've checked. I don't see any issue. Please provide a script that demonstrates the issue.

@Kludex Kludex closed this as not planned Won't fix, can't repro, duplicate, stale Aug 20, 2024
@majiang213
Copy link
Author

majiang213 commented Aug 21, 2024 •
edited
Loading

I've checked. I don't see any issue. Please provide a script that demonstrates the issue.

Sorry. I am now offering a MRE.

from starlette.applications import Starlette
from starlette.responses import JSONResponse, FileResponse
from starlette.routing import Route


async def json(request):
    print("start json")
    return JSONResponse({'hello': 'world'})

async def file(request):
    print("start file")
    return FileResponse("text_file.txt")

routes = [
    Route("/json", endpoint=json),
    Route("/file", endpoint=file)
]

app = Starlette(debug=True, routes=routes)

This is the file returned by the file interface
text_file.txt

This is the log of 50 threads accessing the file interface at the same time

start file
start file
start file
INFO:     127.0.0.1:54279 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54281 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54280 - "GET /file HTTP/1.1" 200 OK
start file
INFO:     127.0.0.1:54287 - "GET /file HTTP/1.1" 200 OK
start file
start file
start file
start file
start file
INFO:     127.0.0.1:54294 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54296 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54295 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54297 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54298 - "GET /file HTTP/1.1" 200 OK
start file
INFO:     127.0.0.1:54299 - "GET /file HTTP/1.1" 200 OK
start file
start file
start file
start file
start file
INFO:     127.0.0.1:54301 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54302 - "GET /file HTTP/1.1" 200 OK
start file
start file
start file
start file
INFO:     127.0.0.1:54303 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54300 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54297 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54304 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54305 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54306 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54307 - "GET /file HTTP/1.1" 200 OK
start file
INFO:     127.0.0.1:54300 - "GET /file HTTP/1.1" 200 OK
start file
INFO:     127.0.0.1:54308 - "GET /file HTTP/1.1" 200 OK
start file
start file
start file
start file
INFO:     127.0.0.1:54309 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54311 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54310 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54312 - "GET /file HTTP/1.1" 200 OK
start file
INFO:     127.0.0.1:54308 - "GET /file HTTP/1.1" 200 OK
start file
start file
INFO:     127.0.0.1:54312 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54311 - "GET /file HTTP/1.1" 200 OK
start file
start file
INFO:     127.0.0.1:54313 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54314 - "GET /file HTTP/1.1" 200 OK
start file
start file
start file
INFO:     127.0.0.1:54315 - "GET /file HTTP/1.1" 200 OK
start file
INFO:     127.0.0.1:54316 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54314 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54313 - "GET /file HTTP/1.1" 200 OK
start file
start file
INFO:     127.0.0.1:54316 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54315 - "GET /file HTTP/1.1" 200 OK
start file
INFO:     127.0.0.1:54318 - "GET /file HTTP/1.1" 200 OK
start file
start file
start file
start file
start file
INFO:     127.0.0.1:54319 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54320 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54321 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54322 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54318 - "GET /file HTTP/1.1" 200 OK
start file
start file
INFO:     127.0.0.1:54323 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54324 - "GET /file HTTP/1.1" 200 OK
start file
INFO:     127.0.0.1:54325 - "GET /file HTTP/1.1" 200 OK
start file
start file
start file
INFO:     127.0.0.1:54328 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54329 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54325 - "GET /file HTTP/1.1" 200 OK
start file
start file
INFO:     127.0.0.1:54331 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54329 - "GET /file HTTP/1.1" 200 OK
start file
start file
INFO:     127.0.0.1:54328 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54325 - "GET /file HTTP/1.1" 200 OK
start file
INFO:     127.0.0.1:54331 - "GET /file HTTP/1.1" 200 OK
start file
start file
INFO:     127.0.0.1:54331 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54329 - "GET /file HTTP/1.1" 200 OK
start file
INFO:     127.0.0.1:54328 - "GET /file HTTP/1.1" 200 OK
start file
start file
INFO:     127.0.0.1:54328 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54329 - "GET /file HTTP/1.1" 200 OK
start file
start file
INFO:     127.0.0.1:54328 - "GET /file HTTP/1.1" 200 OK
INFO:     127.0.0.1:54329 - "GET /file HTTP/1.1" 200 OK

This is the log of 50 threads accessing the json interface at the same time

start json
INFO:     127.0.0.1:58458 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58459 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58463 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58481 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58482 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58483 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58484 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58485 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58481 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58485 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58484 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58486 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58487 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58488 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58489 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58490 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58486 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58491 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58490 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58493 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58494 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58495 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58496 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58497 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58493 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58494 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58498 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58500 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58501 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58502 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58503 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58504 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58505 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58503 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58505 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58508 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58509 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58510 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58508 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58511 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58510 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58509 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58508 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58516 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58517 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58518 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58523 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58517 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58516 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58523 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58518 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58517 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58523 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58523 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58518 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58517 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58516 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58523 - "GET /json HTTP/1.1" 200 OK
start json
INFO:     127.0.0.1:58527 - "GET /json HTTP/1.1" 200 OK

You can see that the interface that return FileResponse("text_file.txt") is sometimes blocked.When the server is under high load, it may take 3-4 seconds to process each request. The first request to be processed will be blocked for a longer time, which may reach 10-30 seconds.Then several requests will respond to the client with HTTP 200 at the same time.
When returning a json, this phenomenon does not occur at all.

You can run uvicorn example:app to start the MRE and reproduce the problem

I'm a little confused as to why this is happening.

This is my environment information

(Starlette) majiang@majiangdeMacBook-Pro Starlette % python --version
Python 3.11.9
(Starlette) majiang@majiangdeMacBook-Pro Starlette % pip list
Package    Version
---------- -------
anyio      4.4.0
click      8.1.7
h11        0.14.0
idna       3.7
pip        24.2
setuptools 72.1.0
sniffio    1.3.1
starlette  0.38.2
uvicorn    0.30.6
wheel      0.43.0

@majiang213
Copy link
Author

majiang213 commented Aug 21, 2024 •
edited
Loading

This is the simulated request configuration I used when testing. You can use it directly
starlette_#2664_postman_collection.json

@Kludex Kludex reopened this Aug 21, 2024
@adriangb
Copy link
Member

adriangb commented Aug 21, 2024 •
edited
Loading

I'm guessing this is because FileResponse uses anyio.open_file (here) which internally uses anyio.to_thread which in turn has a CapacityLimiter(40).

@majiang213 can you try #1724 (comment) and set the tokens to some large number?

@Kludex IMO we should just allow a thread per-file. Otherwise I think we may even hit deadlocks (not sure if that's what is happening in this PR or not...)

@Kludex
Copy link
Member

Kludex commented Aug 21, 2024

There's no blocking code here. The output from the file endpoint doesn't prove that.

@Kludex Kludex closed this as completed Aug 21, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@adriangb @Kludex @majiang213