RuntimeError: Stream consumed when reading body with startlette (bug since 1.9.10)

[sevaho]

How do you use Sentry?

Sentry Saas (sentry.io)

Version

1.9.10

Steps to Reproduce

Server:

import sentry_sdk

from fastapi import FastAPI, Request

sentry_sdk.init()

app = FastAPI()


@app.post("/")
async def index(request: Request):
    r = await request.body()
    return {"Hello": "World"}

Run with uvicorn:

uvicorn app:app --port 5000

As client do:

#! /usr/bin/python
import httpx

import asyncio


async def main():
    image = b"\x89PNG\r\n\x1a\n\x00\x00\x00\rIHDR\x00\x00\x00\x01\x00\x00\x00\x01\x08\x06\x00\x00\x00\x1f\x15\xc4\x89\x00\x00\x00\rIDATx\xdac\xfc\xcf\xf0\xbf\x1e\x00\x06\x83\x02\x7f\x94\xad\xd0\xeb\x00\x00\x00\x00IEND\xaeB`\x82"
    files = {"file": ("test.png", image)}
    async with httpx.AsyncClient() as client:
        r = await client.post(
            "http://localhost:5000/",
            files=files,
        )
        print(r)


asyncio.run(main())

Expected Result

To succeed.

Actual Result

ERROR: Exception in ASGI application
Traceback (most recent call last):
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/uvicorn/protocols/http/h11_impl.py", line 404, in run_asgi
result = await app( # type: ignore[func-returns-value]
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/uvicorn/middleware/proxy_headers.py", line 78, in call
return await self.app(scope, receive, send)
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/fastapi/applications.py", line 270, in call
await super().call(scope, receive, send)
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/sentry_sdk/integrations/starlette.py", line 293, in _sentry_patched_asgi_app
return await middleware(scope, receive, send)
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/sentry_sdk/integrations/asgi.py", line 138, in _run_asgi3
return await self._run_app(scope, lambda: self.app(scope, receive, send))
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/sentry_sdk/integrations/asgi.py", line 187, in _run_app
raise exc from None
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/sentry_sdk/integrations/asgi.py", line 182, in _run_app
return await callback()
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/starlette/applications.py", line 124, in call
await self.middleware_stack(scope, receive, send)
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/sentry_sdk/integrations/starlette.py", line 98, in _create_span_call
await old_call(*args, **kwargs)
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/starlette/middleware/errors.py", line 184, in call
raise exc
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/starlette/middleware/errors.py", line 162, in call
await self.app(scope, receive, _send)
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/sentry_sdk/integrations/starlette.py", line 191, in _sentry_exceptionmiddleware_call
await old_call(self, scope, receive, send)
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/sentry_sdk/integrations/starlette.py", line 98, in _create_span_call
await old_call(*args, **kwargs)
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/starlette/middleware/exceptions.py", line 79, in call
raise exc
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/starlette/middleware/exceptions.py", line 68, in call
await self.app(scope, receive, sender)
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/sentry_sdk/integrations/starlette.py", line 98, in _create_span_call
await old_call(*args, **kwargs)
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/fastapi/middleware/asyncexitstack.py", line 21, in call
raise e
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/fastapi/middleware/asyncexitstack.py", line 18, in call
await self.app(scope, receive, send)
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/starlette/routing.py", line 706, in call
await route.handle(scope, receive, send)
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/starlette/routing.py", line 276, in handle
await self.app(scope, receive, send)
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/starlette/routing.py", line 66, in app
response = await func(request)
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/sentry_sdk/integrations/fastapi.py", line 106, in _sentry_app
return await old_app(*args, **kwargs)
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/fastapi/routing.py", line 231, in app
raw_response = await run_endpoint_function(
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/fastapi/routing.py", line 160, in run_endpoint_function
return await dependant.call(**values)
File "/home/sevaho/gitlab/centurion/./app.py", line 14, in read_root
r = await request.body()
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/starlette/requests.py", line 234, in body
async for chunk in self.stream():
File "/home/sevaho/.cache/pypoetry/virtualenvs/centurion-X1KYOsH6-py3.10/lib/python3.10/site-packages/starlette/requests.py", line 215, in stream
raise RuntimeError("Stream consumed")
RuntimeError: Stream consumed

[antonpirker]

Hey @sevaho

Thanks for reporting this. We will have a look when there is time. (Honestly I thought I have fixed this already...)

[sevaho]

Thanks @antonpirker !

Looks like there is more to it as well.

@app.post("/")
async def index(request: Request, file: UploadFile = File(...)):
    print(file.filename)
    f = await file.read()
    print(f)
    return ""

Whatever file you pass, the content for await file.read() is always empty due to sentry-sdk absorbing it?

[mociepka]

I am facing the same issue in one of the projects I am involved. I can share just traceback:

If you need more details, I am happy to help.

[mecampbellsoup]

Downgrading to ~1.8 for the time being. Saw this bug on version 1.10.1.

[ranjith19]

I had about 20k errors caused by this since yesterday and I was off. Downgraded the library once I figured this out. Lost a lot of API calls.

Is there a way to reset quota on sentry because this bug was essentially caused due to sentry library issue?

[antonpirker]

Hello! I will have a look at this first thing on Monday!

[antonpirker]

I was (unplanned so) afk Monday and Tuesday, so I am looking into this now.

[antonpirker]

This is happening because of some inconsistencies on how Starlette (the foundation of FastAPI) is dealing with request data:

I am now investigating if this should be fixed in Starlette/FastAPI or in Sentry:
encode/starlette#1933

[hasier]

Considering this has been the way starlette has worked for a while now, maybe we could consider the Sentry SDK has "misused" form() and get the fix done here? (To be clear, I do feel starlette has a bit of an inconsistent API for these attributes so it'd be good to clarify with them in encode/starlette#1933 if it's actually expected and straighten it out, but it's also true that form() has worked like this for a while) Also, many people using Sentry won't be able to get into the latest Starlette version straight away - mainly because a lot of people using FastAPI depend on its pin on Starlette-, so adding the fix here and marking the version 1.9.10 as yanked would make it immediately work for everyone, as well as unblocking further updates of the Sentry SDK library seeing as how people are downgrading to get around the issue.

I am thinking maybe it'd be an option to work around the caching issue by getting it consumed into body() first and introduce a test that breaks when Starlette has their issue fixed? The test could simply be 1) call request.form() 2) expect an exception calling request.body(). When that happens, the workaround can then be removed and maybe Sentry SDK could specify the minimum pin to use Starlette so that it goes hand in hand with the fix. wdyt?

# sentry_sdk/integrations/starlette.py
from starlette.datastructures import FormData
from starlette.formparsers import FormParser, MultiPartParser

async def form(self):
    # type: (StarletteRequestExtractor) -> typing.Optional[typing.Mapping[str, typing.Any]]
    if multipart is None:
        return None

    # Parse the body first to get it cached, as Starlette does not cache form() as it
    # does with body() and json() https://github.com/encode/starlette/discussions/1933
    await self.request.body()
    return await self.request.form()

EDIT: PR by @antonpirker following this approach #1724 Thanks! 🙏

[vduseev]

Spent a couple of hours debugging this issue until stumbling upon this ticket. Had zero suspicion that it's Sentry causing it. I was so confused: "how could the body stream be already consumed?". Turns out, the only way to get around it is to downgrade FastAPI or to turn off Sentry.

Here is the piece of code causing this issue:

@app.post(
    "/html",
)
async def post_html_resource(
    request: Request,
):
    data = await request.body()

Where app is a FastAPI class instance and the request is supposed to accept a string as a body. Sentry is initialized before the app instance.

[hasier]

I think this issue can be marked as solved, as it's been fixed in version 1.11.0 (it's working for me at least). Thanks for your work @antonpirker! 🙇

[MrSaints]

This appears to still be an issue for us in v1.11.1. Not sure if we are doing something wrong. Will investigate further.

[br-follow]

Yeah I am seeing this as well in v1.11.1

[Sebadst]

having the issue as well in v1.13.0 . Can we please consider re-opening it?

[ranjith19]

Is this fixed in v1.19.x?

[caner-cetin]

:(

[smzelek]

Seeing this in 1.25.1 and not really understanding the circumstances that cause it. Anyone got a useful link?

[acnebs]

To everyone commenting that this is still broken, please ensure you are not using any other middlewares, as it is not just Sentry that would cause this issue. Any middleware which reads from the request's form() method is going to break if that result is not cached. Realistically this is a bug / design flaw with Starlette/FastAPI that should be fixed on that end.

@caner-cetin if you are not even using this library, then this is definitely not the place you should be commenting. Try commenting on an existing issue in the Starlette or FastAPI repos, or making your own in those repos.

[smzelek]

I wanted to come back here to say that the issue I experienced was actually due to exception handling middleware I wrote that should've checked whether the Request had been disconnected.

FastAPI will catch when the Request stream is disconnected, which eventually gets raised as a starlette.exceptions.HTTPException, with an upstream error of RuntimeError("Stream consumed"). All CustomRouteHandler style Middlewares will be in the stack trace, even though they have nothing to do with the error. (SentrySDK is implemented in this style as well, which is why it will appear in the stack trace and lead one to think its related to the error.)

The solution to this is to check for instances of starlette.exceptions.HTTPException and check if the request was disconnected.

Leaving this example here for posterity, as I imagine lots of other people will get confused seeing sentry in the stacktrace if they do something similar, as this is a common approach to writing a generic FastAPI middleware.

class CustomRouteHandler(APIRoute):
    def get_route_handler(self) -> Callable:
        original_route_handler = super().get_route_handler()

        async def handle_route(request: Request) -> Response:
            try:
                response = await original_route_handler(request)

            except Exception as exc:
                if not await request.is_disconnected():
                    # ... handle non-disconnect errors

                response = ApiErrorResponse(error=ErrorDetails(code=..., message='...'))

            return response

[caner-cetin]

@acnebs Yep, I am sorry for my needless outrage, problem was in MinIO Python SDK, it was reading the stream and not rewinding after read, leaving me with errors when trying to read the same file after uploading to MinIO.

Sorry again! <3