Seemingly random error RuntimeError: No Reponse returned.

[havardthom]

• Related discussion: `RuntimeError` with custom middleware when client drops connection before request finished #1527

Same error though I don't know if cause is the same, we have not been able to reproduce the error in our environments.

The issue

Our frontend is getting HTTP 500 errors from our FastAPI backend. The error is shown below. The error is seemingly random, we have not been able to reproduce it. The traceback does not lead anywhere to our own source code. It has happened on multiple different endpoint requests. We have wrapped our endpoint code in try/except blocks to catch any "hidden" error in our code to trigger this, but it did not catch anything, leading me to believe that this is an underlying error in the framework.

We discovered the error on FastAPI v0.71.0 (Starlette v0.17.1).
We tried upgrading FastAPI to v0.76.0 (Starlette v0.18.0), the error became more frequent.
We have now downgraded FastAPI to v0.68.2 hoping that the error dissipates.

python v3.8
uvicorn v0.15.0

INFO:   xxx - "POST /api/xxx HTTP/1.1" 500
ERROR:  Exception in ASGI application
Traceback (most recent call last):
  File "/xxx/venv/lib64/python3.8/site-packages/uvicorn/protocols/http/httptools_impl.py", line 375, in run_asgi
    result = await app(self.scope, self.receive, self.send)
  File "/xxx/venv/lib64/python3.8/site-packages/uvicorn/middleware/proxy_headers.py", line 75, in __call__
    return await self.app(scope, receive, send)
  File "/xxx/venv/lib64/python3.8/site-packages/fastapi/applications.py", line 208, in __call__
    await super().__call__(scope, receive, send)
  File "/xxx/venv/lib64/python3.8/site-packages/starlette/applications.py", line 112, in __call__
    await self.middleware_stack(scope, receive, send)
  File "/xxx/venv/lib64/python3.8/site-packages/starlette/middleware/errors.py", line 181, in __call__
    raise exc
  File "/xxx/venv/lib64/python3.8/site-packages/starlette/middleware/errors.py", line 159, in __call__
    await self.app(scope, receive, _send)
  File "/xxx/venv/lib64/python3.8/site-packages/starlette/middleware/base.py", line 63, in __call__
    response = await self.dispatch_func(request, call_next)
  File "/xxx/venv/lib64/python3.8/site-packages/prometheus_fastapi_instrumentator/instrumentation.py", line 172, in dispatch_middleware
    raise e from None
  File "/xxx/venv/lib64/python3.8/site-packages/prometheus_fastapi_instrumentator/instrumentation.py", line 169, in dispatch_middleware
    response = await call_next(request)
  File "/xxx/venv/lib64/python3.8/site-packages/starlette/middleware/base.py", line 45, in call_next
    raise RuntimeError("No response returned.")
RuntimeError: No Reponse returned.

[xome4ok]

I was just about to report this very issue, seems like I'm not the only one who are struggling with that.

I've been able to consistently reproduce it.
The key point is to have more than one middleware. When a client disconnects before the server responds to them, we see No response returned in the logs.

fastapi==0.74.1
starlette==0.17.1
uvicorn==0.17.5

import asyncio
import contextlib
import threading
import time

import requests
import uvicorn
from starlette.applications import Starlette
from starlette.middleware import Middleware
from starlette.middleware.base import BaseHTTPMiddleware
from starlette.responses import PlainTextResponse
from uvicorn import Config


class Server(uvicorn.Server):
    """Uvicorn server in a thread.

    https://stackoverflow.com/a/66589593
    """
    def install_signal_handlers(self):
        pass

    @contextlib.contextmanager
    def run_in_thread(self):
        thread = threading.Thread(target=self.run)
        thread.start()
        try:
            while not self.started:
                time.sleep(1e-3)
            yield
        finally:
            self.should_exit = True
            thread.join()


class MyMiddleware(BaseHTTPMiddleware):
    async def dispatch(self, request, call_next):
        return await call_next(request)


# We need to add two middlewares to reproduce the issue
app = Starlette(middleware=[Middleware(MyMiddleware), Middleware(MyMiddleware)])


@app.route('/')
async def root(_):
    """Simulate a delay to be able to disconnect the client before the server responds."""
    await asyncio.sleep(2)
    return PlainTextResponse()


def main():
    """Start the server and make a request with timeout less than server response delay.

    Observe "RuntimeError: No response returned" in the logs.
    """
    server = Server(config=Config(app=app, host="0.0.0.0", port=8000))
    with server.run_in_thread():
        requests.get("http://0.0.0.0:8000/", timeout=1)


if __name__ == "__main__":
    main()

[havardthom]

Alright this is a tough one, been debugging for a while.

First off, i don't think the cause of my issue is the same as the discussion #1527 or the response above. My frontend client is awaiting the response from the server and showing the 500 internal server error in the GUI, so it is not disconnecting before the server responds.

I've found a reproducible case for the bug in our application. As a temporary bugfix i have downgraded FastAPI to v0.68.2 (starlette v0.14.2), the error is introduced for us in v.0.69.0 (starlette v0.15.0).

I believe this is caused by an unfortunate combination of middleware. We are using both GZipMiddleware and Prometheus FastAPI Instrumentator (middleware).

GZipMiddleware has a bug which throws a uvicorn exception RuntimeError: Response content longer than Content-Length for empty responses, a 204_no_content response in my case. This exception is normally post-response so the client wont see it,

But when i add the Prometheus Instrumentator middleware, it seems that this exception is caught and reraised, ultimately leading to the RuntimeError: No response returned error and 500_internal_server_error response to my frontend client.

What i don't understand:

• Why does Prometheus Instrumentator middleware cause the exception to be pre-response instead of post-response?
• There are multiple No response returned errors from subsequent calls to different endpoints after the original RuntimeError: Response content longer than Content-Length error from my 204_no_content endpoint. So it feels like the exception "hangs around" in the middleware, also causing other endpoints to fail.

Hoping some starlette/uvicorn/middleware experts have some insight here.

Relevant issues:
fastapi/fastapi#4050 (GZipMiddleware RuntimeError: Response content longer than Content-Length bug)
trallnag/prometheus-fastapi-instrumentator#108 (Prometheus Instrumentator middleware exception handling issue)

[Kludex]

We solved the GZipMiddleware issue a couple of days ago. You can look for my PRs, it's one of the latest merged. It will be available on the next release - the issue was on the BaseHTTPMiddleware.

I'm away from the computer for some days, so I'll not be able to help. What I can say is that the BaseHTTPMiddleware has more issues, which we are aware, but there shouldn't be any regression on the latest versions related to that piece of code.

There are not that many issues, and PRs, you can see the issues it has.

EDIT: This was the fix for GZipMiddleware: #1609 .

[havardthom]

Great! Hopefully that fix will solve this issue. It does feel like the RuntimeError: No response returned 500 errors are a result of the first GZipMiddleware post-response exception.

I have been trying to reproduce this bug in a simple app, but have not been able, so it is not just the combination of GZipMiddleware and Prometheus middleware, something else is needed in the mix.

Looking forward to next release.

[Kludex]

No, that shouldn't solve the issue here.

I don't have the issue with this branch: #1441... Using the @xome4ok snippet to check that. Can someone confirm?

[havardthom]

I was able to reproduce and solve my issue. The last piece of the puzzle was an aioredis client used in both a dependency and a background task.

This causes 500_internal_server error responses following a request to a 204_no_content endpoint.

Client:

Server:

Recapping the reproduced issue:

• I have a 204_no_content endpoint which causes a post-response exception RuntimeError: Response content longer than Content-Length. But this exception is thrown before redis_bg_task has started.
• If I add a BaseHTTPMiddleware to the app, the 204_no_content exception is thrown after redis_bg_task has started instead. I'm guessing this leaves the aioredis client in some kind of erronous state due to bad resource allocation in redis-py<=4.2.1.
• All following requests to endpoints using the aioredis client will fail with 500 error. I don't know what throws this exception.

Solution:

• Remove BaseHTTPMiddleware
  OR
• Upgrade redis-py>4.2.1. The error goes away with redis-py v4.2.2 (https://github.com/redis/redis-py/releases/tag/v4.2.2)

Reproduced issue:

fastapi==0.78.0
uvicorn[standard]==0.17.6
httpx==0.22.0
redis==4.2.1

# test_starlette_issue_1634.py
# start redis service: docker run -d -p 6379:6379 --name myredis redis
# start server: uvicorn --factory test_starlette_issue_1634:create_app --reload
# send requests: python test_starlette_issue_1634.py
import asyncio

from fastapi import FastAPI, status, Request, BackgroundTasks, Depends, APIRouter
from starlette.middleware.base import BaseHTTPMiddleware

import httpx
from redis import asyncio as aioredis


def get_redis(r: Request):
    return r.app.state.redis

async def redis_dependency(redis = Depends(get_redis)):
    print("redis_dependency start")
    value = await redis.get("my-key")
    print("redis_dependency end")
    return value

async def redis_bg_task(redis):
    print("redis_bg_task start")
    await redis.publish("test", "test")
    print("redis_bg_task end")


router = APIRouter()

@router.get("/")
def root(value = Depends(redis_dependency)):
    print("value root endpoint", value)
    return {"Hello": "World"}


@router.get("/no_content", status_code=status.HTTP_204_NO_CONTENT)
async def no_content(
    background_tasks: BackgroundTasks, 
    redis = Depends(get_redis),
    value = Depends(redis_dependency)
):
    print("value no_content endpoint", value)
    background_tasks.add_task(redis_bg_task, redis)

class MyMiddleware(BaseHTTPMiddleware):
    async def dispatch(self, request, call_next):
        return await call_next(request)

def create_app():
    app = FastAPI()

    app.add_middleware(MyMiddleware)

    app.state.redis = aioredis.from_url("redis://localhost")

    app.include_router(router)

    return app


if __name__ == "__main__":
    async def send_requests():
        async with httpx.AsyncClient(base_url="http://127.0.0.1:8000") as client:
            r = await client.get("/no_content")
            print(r)
            await asyncio.sleep(0.1)
            r = await client.get("/")
            print(r)

    asyncio.run(send_requests())

[Kludex]

The last message has a different error than the one in the description of this issue. As I said before, the issue caused between the interaction of GZipMiddleware and BaseHTTPMiddleware was already solved (#1609).

EDIT: I've reread the last message... We are working on a solution for the interaction of bkg tasks and the BaseHTTPMiddleware on #1441.

[havardthom]

Some adjustments to the reproduced issue to give exception from original description, solutions (from my previous post) are still the same.

Edit: It would be nice to know what throws the exception, but i don't know how to catch it, try/except in redis_dependency does not catch anything

redis_dependency start
INFO:     127.0.0.1:51642 - "GET / HTTP/1.1" 500 Internal Server Error
ERROR:    Exception in ASGI application
Traceback (most recent call last):
  File "/home/havardthom/test_starlette_bug/py38/lib/python3.8/site-packages/starlette/middleware/base.py", line 43, in call_next
    message = await recv_stream.receive()
  File "/home/havardthom/test_starlette_bug/py38/lib/python3.8/site-packages/anyio/streams/memory.py", line 94, in receive
    return self.receive_nowait()
  File "/home/havardthom/test_starlette_bug/py38/lib/python3.8/site-packages/anyio/streams/memory.py", line 87, in receive_nowait
    raise EndOfStream
anyio.EndOfStream

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/havardthom/test_starlette_bug/py38/lib/python3.8/site-packages/uvicorn/protocols/http/httptools_impl.py", line 372, in run_asgi
    result = await app(self.scope, self.receive, self.send)
  File "/home/havardthom/test_starlette_bug/py38/lib/python3.8/site-packages/uvicorn/middleware/proxy_headers.py", line 75, in __call__
    return await self.app(scope, receive, send)
  File "/home/havardthom/test_starlette_bug/py38/lib/python3.8/site-packages/fastapi/applications.py", line 269, in __call__
    await super().__call__(scope, receive, send)
  File "/home/havardthom/test_starlette_bug/py38/lib/python3.8/site-packages/starlette/applications.py", line 124, in __call__
    await self.middleware_stack(scope, receive, send)
  File "/home/havardthom/test_starlette_bug/py38/lib/python3.8/site-packages/starlette/middleware/errors.py", line 184, in __call__
    raise exc
  File "/home/havardthom/test_starlette_bug/py38/lib/python3.8/site-packages/starlette/middleware/errors.py", line 162, in __call__
    await self.app(scope, receive, _send)
  File "/home/havardthom/test_starlette_bug/py38/lib/python3.8/site-packages/starlette/middleware/base.py", line 68, in __call__
    response = await self.dispatch_func(request, call_next)
  File "/home/havardthom/test_starlette_bug/./test_starlette_issue.py", line 55, in dispatch
    return await call_next(request)
  File "/home/havardthom/test_starlette_bug/py38/lib/python3.8/site-packages/starlette/middleware/base.py", line 47, in call_next
    raise RuntimeError("No response returned.")
RuntimeError: No response returned.

# test_starlette_issue_1634.py
# start redis service: docker run -d -p 6379:6379 --name myredis redis
# start server: uvicorn --factory test_starlette_issue_1634:create_app --reload
# send requests: python test_starlette_issue_1634.py
import asyncio

from fastapi import FastAPI, status, Request, BackgroundTasks, Depends, APIRouter
from starlette.middleware.base import BaseHTTPMiddleware

import httpx
from redis import asyncio as aioredis

class TestClass():
    def __init__(self, redis):
        self.redis = redis
    
    async def __call__(self):
        value = await self.redis.get("my-key")
        return value

def get_redis(r: Request):
    return r.app.state.redis

async def redis_dependency(r: Request):
    print("redis_dependency start")
    value = await r.app.state.get_test_class()
    print("redis_dependency end")
    return value

async def redis_bg_task(redis):
    print("redis_bg_task start")
    await redis.publish("test", "test")
    print("redis_bg_task end")


router = APIRouter()

@router.get("/")
def root(value = Depends(redis_dependency)):
    print("value root endpoint", value)
    return {"Hello": "World"}


@router.get("/no_content", status_code=status.HTTP_204_NO_CONTENT)
async def no_content(
    background_tasks: BackgroundTasks, 
    redis = Depends(get_redis),
    value = Depends(redis_dependency)
):
    print("value no_content endpoint", value)
    background_tasks.add_task(redis_bg_task, redis)

class MyMiddleware(BaseHTTPMiddleware):
    async def dispatch(self, request, call_next):
        return await call_next(request)

def create_app():
    app = FastAPI()

    app.add_middleware(MyMiddleware)

    app.state.redis = aioredis.from_url("redis://localhost")
    app.state.get_test_class = TestClass(app.state.redis)

    app.include_router(router)

    return app


if __name__ == "__main__":
    async def send_requests():
        async with httpx.AsyncClient(base_url="http://127.0.0.1:8000") as client:
            print("GET /no_content")
            r = await client.get("/no_content")
            print(r)
            await asyncio.sleep(0.1)
            print("GET /")
            r = await client.get("/")
            print(r)
            await asyncio.sleep(0.1)
            print("GET /")
            r = await client.get("/")
            print(r)

    asyncio.run(send_requests())