Replies: 13 comments 1 reply
-
|
Some additional details here. We added some middleware to see if we could further debug where it was hanging: """Custom asgi middleware."""
import ddtrace
class TraceSendReceiveAsgiMiddleware:
"""Middleware to trace each message sent and received in a connection."""
def __init__(self, app):
"""Initialize the middleware."""
self.app = app
async def __call__(self, scope, receive, send):
"""Invoke the middleware."""
async def wrapped_receive():
with ddtrace.tracer.trace("receive"):
return await receive()
async def wrapped_send(message):
with ddtrace.tracer.trace("send"):
return await send(message)
return await self.app(scope, wrapped_receive, wrapped_send)With this, we see that for these cases, it does seem to be stuck on the
I also attempted to fully convert to asynchronous endpoints, upgraded to SQLAlchemy 1.4, leveraged its new async support, and moved the endpoints themselves to be async as well. However, I see the same behavior even with the async endpoints. I'll update the ticket title to reflect this, as it doesn't seem isolated to sync endpoints. Also should note that the current client for this is using |
Beta Was this translation helpful? Give feedback.
-
|
Also tried to remove gunicorn/uvicorn from the equation, and replaced them with hypercorn. The behavior is similar, though with some interesting differences. First, it didn't fail after the 3 minute mark, but instead took over 11 minutes to complete, presumably because hypercorn doesn't axe the request on connection close.
It also doesn't give a return code however, and I actually see an error in the logs, which may be helpful: |
Beta Was this translation helpful? Give feedback.
-
|
I'm having a similar issue. |
Beta Was this translation helpful? Give feedback.
-
|
I think I've figured this out, though not sure if this is really a problem with FastAPI or with In short, the requests themselves aren't actually taking this long, it's just that the client has bailed, and FastAPI just keeps waiting. I have a (mostly) reproducible example now: DockerFile: /app/main.py: from fastapi import FastAPI
from pydantic import BaseModel
import time
class TimingMiddleware:
"""Middleware to track request time."""
def __init__(self, app):
"""Initialize the middleware."""
self.app = app
async def __call__(self, scope, receive, send):
"""Invoke the middleware."""
async def wrapped_receive():
start = time.time()
data = await receive()
end = time.time()
print(f"RECEIVED IN {end-start}")
return data
return await self.app(scope, wrapped_receive, send)
app = FastAPI()
app.add_middleware(TimingMiddleware)
class Item(BaseModel):
data: str
@app.post("/endpoint")
def endpoint(item: Item):
return {"Hello": "World"}test_client.py: import asyncio
import httpx
import time
async def make_request(client):
# post a big chunk of data
await client.post("http://localhost/endpoint", json={"data": "A" * 10000000})
return "XXX"
async def main():
async with httpx.AsyncClient(timeout=httpx.Timeout(read=5, connect=5, pool=5, write=0.00000000000000000000000000000000000000001)) as client:
tasks = []
for x in range(5):
tasks.append(asyncio.create_task(make_request(client)))
# Gather all tasks
done = await asyncio.gather(*tasks, return_exceptions=True)
print(done) # Should always print WriteTimeout.
# Just sleep for 10 seconds. Connections wont be released until the end of this.
time.sleep(10)
asyncio.run(main())Start the FastAPI server. docker build -t timeout .
docker run --rm --name timeout -p 80:80 timeoutRun the test client: python test_client.pyYou'll observe that %python test_client.py
[WriteTimeout(''), WriteTimeout(''), WriteTimeout(''), WriteTimeout(''), WriteTimeout('')]But that FastAPI doesn't register any output until 10 seconds later, when the client closes the connections. If you extend the wait time to 3 minutes, the same behavior occurs. I'm not sure what the expected behavior really should be. It does seem that httpx could potentially be better about notifying the server that nothing else is coming, but also seems that something is potentially awry with how keep-alives are working with gunicorn/uvicorn/fastapi. Ideally, the server should be configurable to time out more proactively on these dead connections. A simple workaround, in my case at least, was to avoid keeping long-lived httpx clients, and instead create a new client and connection for each request. This is probably worse from a performance perspective, but it does prevent these sort of confusing timings. |
Beta Was this translation helpful? Give feedback.
-
|
In my case, I use httpx but to call another webservice from my fastapi app, my clients are browser and it sometimes hangs (indefinitely for FF and canceled after 4s by chrome). |
Beta Was this translation helpful? Give feedback.
-
|
@TimOrme I also had a problem with blocking requests. Look here for solutions to this problem |
Beta Was this translation helpful? Give feedback.
-
|
Thanks for the report and discussion! ☕ This was possibly solved in #5122, released as part of FastAPI 0.82.0 🎉 Could you check it? If this solves it for you, you could close the issue. 🤓 |
Beta Was this translation helpful? Give feedback.
-
|
Assuming the original need was handled, this will be automatically closed now. But feel free to add more comments or create new issues or PRs. |
Beta Was this translation helpful? Give feedback.
-
|
@tiangolo as of 0.82.0 it doesn't seem to be resolved. I'm having a hard time reproducing this, since it happens randomly: Environment
As @TimOrme has mentioned this isn't a load issue — the requests never reach the server. |
Beta Was this translation helpful? Give feedback.
-
|
Same issue 😭 |
Beta Was this translation helpful? Give feedback.
-
|
I think I have the same issue. But only in my production environment. It just hangs and I never get a response. Also happening in the browser. Looking at the logs with TRACE level in uvicorn: Here there is a 15m 40s delay between receiving the request and handling it. This is happening on FastAPI v0.95.2 and Python 3.11.4. Not sure how to solve this. Tried debugging with GDB but it just hangs waiting for the futex... Anyone got any ideas what to check next? |
Beta Was this translation helpful? Give feedback.
-
|
It turns out the problem was a firewall dropping the database connection after 30 minutes of inactivity. Setting |
Beta Was this translation helpful? Give feedback.
-
|
We also had the same issue in our production environment.
As a workaround, we added an override for the Please note: This workaround only helps to "fail faster". It helps because we can retry directly again and get to the successful response much quicker, but isn't an ultimate solution. This was helpful for us as a temporary workaround, we ultimately fixed it by moving from GKE Autopilot to a non-autopilot cluster. Here's the code we added for faster timeouts when receiving request data: |
Beta Was this translation helpful? Give feedback.
-
|
Hi everyone, we are still facing the same or similar issue. We think it's related to Uvicorn. Here is a brief example to reproduce it. We've tried different Python (3.10, 3.11, 3.12), FastAPI (0.78, 0.111) and Uvicorn versions according to FastAPi reqs, and we're still getting the same behaviour. We've tested it in Mac and Ubuntu. Furthermore, we've tested the same beahaviour using Flask, Express, both of them work smoothly. Definetly something is happening. This is the API Code ( Here are the snippets: # fast_api_server.py
from fastapi import FastAPI
from pydantic import BaseModel
import time
class UserMessage(BaseModel):
userMessage: str
app = FastAPI()
@app.post("/sample")
def sample(user_message: UserMessage):
print('Received JSON data:', user_message)
return {
"responseFromFastAPI": (
f'Your messaage: "{user_message.userMessage}"'
)
}
@app.get("/ping")
async def ping():
return "pong"
# Run the FastAPI application
if __name__ == "__main__":
import uvicorn
uvicorn.run(app, host="0.0.0.0", port=8080)# flask_api_server.py
from flask import Flask, request, jsonify
from pydantic import BaseModel, ValidationError
import time
app = Flask(__name__)
class UserMessage(BaseModel):
userMessage: str
@app.route("/sample", methods=["POST"])
def sample():
try:
user_message = UserMessage(**request.json)
except ValidationError as e:
return jsonify(e.errors()), 400
print('Received JSON data:', user_message)
# Simulate a delay if wanted
return jsonify({
"responseFromFlask": (
f'Your messaage: "{user_message.userMessage}"'
)
})
@app.route("/ping", methods=["GET"])
def ping():
return "pong"
if __name__ == "__main__":
app.run(host="0.0.0.0", port=8080)After running any of the servers. Please ensure you are forwarding your tunnel using Dev Tunnels # test_apis.py
import requests
import threading
import time
# The URL of the endpoint you want to test
# ENDPOINT_URL, NUM_THREADS = "http://0.0.0.0:8000", 200 # LOCAL TEST: Replace with your actual endpoint URL (Fast Enough no issues)
ENDPOINT_URL, NUM_THREADS = "https://something.use2.devtunnels.ms", 50 # TODO: CHANGE THIS
# Number of threads (simultaneous requests)
# Timeout duration for each request
TIMEOUT = 10
# Function to send a GET request to the endpoint with a timeout
def send_request(thread_id):
try:
start_time = time.time()
resp = requests.post(
f"{ENDPOINT_URL}/sample",
# data={"userMessage": f"Ejemplo {start_time}"},
json={"userMessage": f"Ejemplo {start_time}"},
timeout=TIMEOUT,
)
# resp = requests.get(
# f"{ENDPOINT_URL}/ping",
# timeout=TIMEOUT,
# )
elapsed_time = time.time() - start_time
print(
f"Thread {thread_id}: Response Code: {resp.status_code}, Time: {elapsed_time:.2f} secs"
)
except requests.exceptions.Timeout:
print(f"Thread {thread_id}: Request timed out after {TIMEOUT} secs")
except requests.exceptions.RequestException as e:
print(f"Thread {thread_id}: Request failed: {e}")
# Function to create multiple threads
def run_multithreaded_test():
threads = []
for i in range(NUM_THREADS):
thread = threading.Thread(target=send_request, args=(i,))
threads.append(thread)
thread.start()
# Wait for all threads to complete
for thread in threads:
thread.join()
if __name__ == "__main__":
run_multithreaded_test()After running it with FastAPI you should see some succeful calls, but suddently the timing starts increasing and some requests begin to timeout. Please run the test 2 or 3 times to have a broader check. At the end you will notice that the requests are not entering the router of FastAPI, which we perceive as an uvicorn issue. Here is a sample log: # test_apis.py - Using FastAPI as server
Thread 32: Response Code: 200, Time: 0.70 secs
Thread 4: Response Code: 200, Time: 0.74 secs
Thread 1: Response Code: 200, Time: 0.74 secs
Thread 6: Response Code: 200, Time: 0.80 secs
Thread 35: Response Code: 200, Time: 0.80 secs
Thread 16: Response Code: 200, Time: 0.80 secs
Thread 49: Response Code: 200, Time: 0.79 secs
Thread 7: Response Code: 200, Time: 0.81 secs
Thread 13: Response Code: 200, Time: 0.81 secs
Thread 0: Response Code: 200, Time: 0.81 secs
Thread 5: Response Code: 200, Time: 0.81 secs
Thread 43: Response Code: 200, Time: 0.80 secs
Thread 36: Response Code: 200, Time: 0.80 secs
Thread 46: Response Code: 200, Time: 0.81 secs
Thread 17: Response Code: 200, Time: 0.82 secs
Thread 31: Response Code: 200, Time: 0.81 secs
Thread 29: Response Code: 200, Time: 0.81 secs
Thread 23: Response Code: 200, Time: 0.82 secs
Thread 30: Response Code: 200, Time: 0.88 secs
Thread 26: Response Code: 200, Time: 0.97 secs
Thread 45: Response Code: 200, Time: 0.97 secs
Thread 28: Request timed out after 10 secs
Thread 21: Request timed out after 10 secs
Thread 48: Request timed out after 10 secs
Thread 19: Request timed out after 10 secs
Thread 15: Request timed out after 10 secs
Thread 37: Request timed out after 10 secs
Thread 41: Request timed out after 10 secs
Thread 22: Request timed out after 10 secsOn the other hand, with Flask you will see that all the requests are processed smoothly, no timeouts are raised despite of taking more time to get the response. If anyone has any thoughts about it or if the test doesn't make sense please let us know. Thank you! |
Beta Was this translation helpful? Give feedback.
Uh oh!
There was an error while loading. Please reload this page.
Uh oh!
There was an error while loading. Please reload this page.
-
Example
I'm having a very hard time reproducing this issue consistently, but have exhausted all other avenues that I could think of. I'll do my best to describe the setup here, but unfortunately I couldn't come up with a code sample that I was able to reproduce it consistently.
The gist is like this however:
We have a simple sync endpoint which inserts keys into the database. The DB operation is very quick. We've also added span traces to debug the behavior using datadog.
Description
Under moderate load, about 10 requests per second, the endpoint mostly responds very fast in the 10ms range. However, sometimes there are extreme outliers in response time, where the request goes to 3 minutes before the connection is killed by our ALB.
Traces during the long operation show that the route code is never hit, nor are the dependencies. This seems to indicate that something within FastAPI is failing to properly schedule or submit the sync jobs into the thread pool [URL details obfuscated to remove company info]
Compared with normal requests:
This seems to be a similar issue to the one described here: https://stackoverflow.com/questions/61466243/uvicorn-not-processing-some-requests-randamly
And similar behavior here: #1195 but we are not on windows.
Environment
Note that gunicorn and uvicorn were upgraded manually in the dockerfile in an attempt to resolve the issue. However, the default versions with the image exhibited the same behavior.
Additional context
We've tried a number of additional ways to reproduce this, but have been unsuccessful. When testing locally, even introducing 10x the load, we can't reproduce this issue.
Also should note this is running in AWS in ECS, behind an ALB. We have toyed with the timeout settings within gunicorn and uvicorn to try and address this as well, but none of those seem to solve it.
Beta Was this translation helpful? Give feedback.
All reactions