starlette icon indicating copy to clipboard operation
starlette copied to clipboard

Question about Request.Body()

Open ricardomomm opened this issue 6 years ago • 7 comments
trafficstars

Hi dears developers, how can I retrieve the request.body inside an exception_handler?

My scenario:

I have an exception_handler hook that receives a request and an exception, I'm also using FastApi which tries to parse the body to a JSON, if it does not work it raises an HTTPException. So I'm trying to build a hook to log invalid JSON requests, this exception is being correctly captured by my exception_handler but when I'm trying to retrieve the body I can't it hangs, it simple doesn't work. It does make sense as after reading for the first time it is being cached inside the Request object but the Request object is being recreated before calling the exception_handler so I'm losing my cache and I'm able to ready from the stream again.

https://github.com/encode/starlette/blob/d23bfd0d8ff68d535d0283aa4099e5055da88bb9/starlette/exceptions.py#L79

Not sure if it is supposed to be like this by design, but I think my scenario is not that fancy, it should be something possible, what do you guys think? Any workaround?

My code:

async def httpexception_logger(request: Request, exc: HTTPException):
    body = await request.body()
    text: str = bytes.decode(body)
    logger.error("Exception at %s, status code: %s, body: %s: exception %s", request.url, exception.status_code, text, exc)
    ... other stuff...

ricardomomm avatar Apr 26 '19 20:04 ricardomomm

What’s the simplest possible code sample someone could use to replicate the issue? (Ideally just using Starlette itself if possible)

lovelydinosaur avatar Apr 26 '19 22:04 lovelydinosaur

I expect there’s an issue with the request body already having been streamed, but we ought to be able to handle things more gracefully.

lovelydinosaur avatar Apr 26 '19 22:04 lovelydinosaur

Hi @tomchristie , I was able to reproduce with the code below:

from starlette.applications import Starlette
from starlette.responses import JSONResponse
from starlette.exceptions import HTTPException
from json.decoder import JSONDecodeError
import uvicorn

# Force an exception sending an invalid json to "/"
# it will trigger an exception and it will be handled
# by log_exceptions and the assert will trigger an
# exception because request.body() cannot be read
# anymore (stream already consumed)

app = Starlette(debug=True)

@app.exception_handler(JSONDecodeError)
async def log_exceptions(request, exc):
    body: bytes = await request.body() # hangs forever
    body_text: str = bytes.decode(body)
    assert body_text, "I could not retrieve the body"
    return JSONResponse({ "error": "Unexpected error happened!" })


@app.route('/', methods=["POST"])
async def homepage(request):
    body_bytes = await request.body()
    if body_bytes:
        json = await request.json()
        return JSONResponse(json)
    return JSONResponse({ "error": "empty body, please send something" }) 


if __name__ == '__main__':
    uvicorn.run(app, host='0.0.0.0', port=8000)

to test:

curl -d "{\"key1\":\"value1\", \"key2\": invalid }" -H "Content-Type: application/json" -X POST http://localhost:8000

ricardomomm avatar Apr 29 '19 12:04 ricardomomm

I have a very similar case running into the same problem: Using FastAPI I would like to log requests and responses for requests that have triggered a HTTPException. My idea was to wrap FastAPIs existing http exception handler like so:

from fastapi.applications import http_exception
from starlette.exceptions import HTTPException
from logging import getLogger

logger = getLogger("uvicorn")

app = FastAPI(title='x')

@app.exception_handler(HTTPException)
async def new_http_exception(request, exc):
    request_json = await request.json()
    response = await http_exception(request, exc)
    log_prefix = f"('{request.client.host}', {request.client.port}) - \"{request.method} {request._scope['path']} {request._scope['type'].upper()}/{request._scope['http_version']}\" {exc}"
    logger.info(f"{log_prefix} request: {request_json}")
    logger.info(f"{log_prefix} response: {response.body.decode()}")
    return response

This hangs forever on the first line.

gwdekker avatar Apr 30 '19 11:04 gwdekker

#495 has this similar issue as well.

ansrivas avatar Apr 30 '19 12:04 ansrivas

@tomchristie , I was reading your comments related to @blueyed changes to store the Request in the Scope and I completely agree that Request should reflect scope, and as scope is used to construct a request perhaps a small change to store/cache the body inside the scope instead of a local var, do you think this could solve this issue?

I did this changes locally just to test and it seems to work but I have not enough knowledge about the impact it may cause:

[email protected]


    async def stream(self) -> typing.AsyncGenerator[bytes, None]:
        if "body" in self._scope:
            yield self._scope["body"]
            yield b""
            return

        if self._stream_consumed:
            raise RuntimeError("Stream consumed")

        self._stream_consumed = True
        while True:
            message = await self._receive()
            if message["type"] == "http.request":
                body = message.get("body", b"")
                if body:
                    yield body
                if not message.get("more_body", False):
                    break
            elif message["type"] == "http.disconnect":
                self._is_disconnected = True
                raise ClientDisconnect()
        yield b""

    async def body(self) -> bytes:
        if not "body" in self._scope:
            body = b""
            async for chunk in self.stream():
                body += chunk
            self._scope["body"] = body
        return self._scope["body"]

ricardomomm avatar May 02 '19 17:05 ricardomomm

Any movements? Without this functionality, we don't have access to origin request on exception handler. This is really strange.

kataev avatar Sep 04 '19 12:09 kataev

Any news? Still having the hanging issue.

tteguayco avatar Mar 03 '23 07:03 tteguayco