Fastapi: [BUG] Awaiting request body in middleware blocks the application

[wyfo]

Describe the bug
Description in the title

To Reproduce
Minimal code:

from typing import Mapping

from fastapi import FastAPI
from starlette.requests import Request

app = FastAPI()

@app.middleware("http")
async def func(request: Request, call_next):
    print(await request.json())
    return await call_next(request)

@app.post("/")
def read_root(arg: Mapping[str, str]):
    return {"Hello": "World"}

Run the application with uvicorn <file>:app
Test the bug with curl localhost:8000 -d '{"status":"ok"}'

Expected behavior
The body of the request is printed, but the curl command stay pending for ever. If it is interrupted (Ctrl-C), the application then print ERROR: Error getting request body:

Environment:

• OS: macOS
• fastapi 0.33.0
• python 3.7.3
• (tested on Ubuntu too with Python 3.7.0 and 3.7.4)

Additional context

• When the route function has no body argument (def read_root():), there is no problem : the body is printed and the response send.
• Thinking the issue was maybe coming from Starlette, I tested the following code, which works without issue. The bug seems thus to come from fastapi

from starlette.applications import Starlette
from starlette.requests import Request
from starlette.responses import JSONResponse

app = Starlette()


@app.middleware("http")
async def func(request: Request, call_next):
    print(await request.json())
    return await call_next(request)


@app.route('/', methods=["POST"])
def homepage(request):
    return JSONResponse({"Hello": "World"})

[euri10]

works fine for me copy-pasting the exact same thing, only had to comment print(await request.json()) which crashed the app

@app.middleware("http")
async def func(request: Request, call_next):
    # print(await request.json())
    return await call_next(request)


@app.post("/bug")
def bug(arg: Mapping[str, str]):
    return {"Hello": "World"}

 ✗ curl -d '{"status":"ok"}' http://localhost:8000/bug
{"Hello":"World"}%             

[wyfo]

works fine for me copy-pasting the exact same thing, only had to comment print(await request.json()) which crashed the app

That's exactly the point, the print statement, or more exactly the ``àwait``` inside blocks the application. The question is why ?
And the other question, more important for me is : how can I log my request payload if i'm not able to await it in middleware ?

[euri10]

I think the middleware is unnecessary, should you want to get your payload just do:

@app.post("/bug")
async def read_root(request: Request, arg: Mapping[str, str]):
    print(await request.json())
    return {"Hello": "World"}

[wyfo]

I think the middleware is unnecessary, should you want to get your payload just do:

But i don't want to just get the payload of one request, i want to log the payloads of EVERY endpoints of my application. I don't want for that to add code in every endpoint, that's the purpose of a middleware.

[dmontagu]

@wyfo It appears this is sort of a Starlette problem -- if you try to access request.json() both inside of and outside of a middleware, you'll run into the same problem you are hitting with fastapi. This has to do with how the json is "cached" inside the starlette Request -- it isn't transferred to the next called asgi app.

You can reproduce the issue in the pure starlette example if you try to print the json contents inside your starlette endpoint:

• change def homepage(request): it to use async def
• add a line containing print(await request.json())

FastAPI grabs the request.json() as part of it's request handling, which is why you run into the issue even without explicitly trying to if using FastAPI.

In order for this to be handled properly, I think it would require fixes in starlette; I feel like I've seen this discussed in starlette issues, but I'm not sure. I'll reference it if I find it. Even if you weren't using FastAPI, you'd face this issue if you didn't do something funny with to store the json after the first time you read it.

---

On the other hand, I think there is a neat workaround for this use case (that actually requires FastAPI), since you don't need your middleware to modify anything before the next handler receives it:

from typing import Mapping

from starlette.requests import Request

from fastapi import FastAPI, APIRouter, Depends

app = FastAPI()
api_router = APIRouter()

@api_router.post("/")
def read_root(arg: Mapping[str, str]):
    return {"Hello": "World"}

async def log_json(request: Request):
    print(await request.json())

# the trick here is including log_json in the dependencies:
app.include_router(api_router, dependencies=[Depends(log_json)])

This requires you to add all endpoints to api_router rather than app, but ensures that log_json will be called for every endpoint added to it (functioning very similarly to a middleware, given that all endpoints pass through api_router).

This works because no new Request instance will be created as part of the asgi request handling process, so the json read off by FastAPI's processing will still be cached on the request when the log_json function is called.

[dmontagu]

@wyfo For what it's worth, it looks like consuming the body inside of middleware is somewhat broadly discouraged -- https://github.com/encode/starlette/issues/495#issuecomment-494008175 (by the creator of starlette):

Consuming request data in middleware is problematic.
Not just to Starlette, but generally, everywhere.

On the whole you should avoid doing so if at all possible.

So the "workaround" I posted above may actually be a better way to handle this than middleware anyway.

[wyfo]

@dmontagu
Thank you a lot ! For your workaround and for retrieving the starlette issue. I don't really understand the point of @tomchristie about that, but it seems I have to continue the discussion in the dedicated place.

[tiangolo]

Thanks for your help @euri10 and @dmontagu.

Agreed with all of @dmontagu's explanation and suggestion.

Thanks @wyfo for reporting back and closing the issue.

[ruslankrivoshein]

I guess, it's useful to use custom Request or Route in some cases.

class LoggedRoute(APIRoute):
    def get_route_handler(self):
        original_route_handler = super().get_route_handler()

        async def log_request_detail(request):
            ref = '{}:{}'.format(*request.scope.get('server', ('', '')))
            protocol = (f'{request.scope.get("type", "unknown").upper()}'
                        f'/'
                        f'{request.scope.get("http_version", "unknown")}')

            try:
                body = await request.json()
            except JSONDecodeError:
                body = {}

            logger.info(f'{ref} - "{request.method} {request.url.path} '
                        f'{protocol}" {body}')

            return await original_route_handler(request)

        return log_request_detail

Proof me wrong