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 -- encode/starlette#495 (comment) (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

[AG-LC]

@dmontagu I used your method, and I get a RuntimeError: Stream consumed exception in the log_request_json function. Do you see what I did wrong?

import logging
import fastapi

import routers

logger = logging.getLogger(__name__)
app = fastapi.FastAPI()

async def log_request_json(request: fastapi.Request):
    logger.debug("request parameters: %s", await request.json())

app.include_router(routers.api_router, dependencies=[fastapi.Depends(log_request_json)])

[liukelin]

 async def set_body(request: Request, body: bytes):
     async def receive() -> Message:
         return {"type": "http.request", "body": body}
     request._receive = receive
 
 async def get_body(request: Request) -> bytes:
     body = await request.body()
     await set_body(request, body)
     return body
 
 @app.middleware("http")
 async def app_entry(request: Request, call_next):
     
     await set_body(request, request.body())
 
     print(await get_body(request))
 
     response = await call_next(request)
     return response

[yushiyangk]

This can be simplified to

@app.middleware('http')
async def request_body_fix(request: Request, call_next):
    body = await request.body()
    async def receive() -> starlette.types.Message:
        return {"type": "http.request", "body": body}
    request._receive = receive
    return await call_next(request)

[PrasannaVpk]

How to use two await keyword within a function to log all the endpoint,if I use so my application does not working.

[ycd]

How to use two await keyword within a function to log all the endpoint,if I use so my application does not working.

@PrasannaVpk Do you mean health-check?

[karthick-optisol]

I cant able to log body json for all post request. Can you please suggest a alternative how to log the request json. Right now it goes to infinite loop and not responding.

 
@app.middleware("http")
async def log_requests(request: Request, call_next):

    
    
    body = await request.body()
    body_req = json.loads(body.decode("utf-8"))
    
    start_time = time.time()
    
    response = await call_next(request)
    
    
    process_time = (time.time() - start_time) * 1000
    formatted_process_time = '{0:.2f}'.format(process_time)

    log_json={
              "uuid":str(uuid.uuid4()),
              "ts":formatted_process_time,
              "env":os.environ.get("ENV"),
              "region":os.environ.get("REGION"),
              "name":os.environ.get("NAME"),
              "type":"request",
              "method":request.method,
              "useragent":request.headers["user-agent"],
              "status_code":response.status_code,
              "url":request.url.path,
              "query":request.query_params,
              "body": body_req ,
              "length":response.headers["content-length"],
              'ts':formatted_process_time
              }
   
    pprint(log_json)
    
   
    return response

class Item(BaseModel):
    name:str
    


@app.post("/hello_world")
async def hello_world(item:Item):
    pprint(item)
    return item

[waynerv]

@karthick-optisol Check out this doc https://fastapi.tiangolo.com/advanced/custom-request-and-route/#accessing-the-request-body-in-an-exception-handler.
Implements it in a custom Route is much easier.

[fawwazihsanr]

 async def set_body(request: Request, body: bytes):
     async def receive() -> Message:
         return {"type": "http.request", "body": body}
     request._receive = receive
 
 async def get_body(request: Request) -> bytes:
     body = await request.body()
     await set_body(request, body)
     return body
 
 @app.middleware("http")
 async def app_entry(request: Request, call_next):
     
     await set_body(request, request.body())
 
     print(await get_body(request))
 
     response = await call_next(request)
     return response

what is "Message" there?

[liukelin]

from starlette.types import Message

@fawwazihsanr

[choich]

 async def set_body(request: Request, body: bytes):
     async def receive() -> Message:
         return {"type": "http.request", "body": body}
     request._receive = receive
 
 async def get_body(request: Request) -> bytes:
     body = await request.body()
     await set_body(request, body)
     return body
 
 @app.middleware("http")
 async def app_entry(request: Request, call_next):
     
     await set_body(request, request.body())
 
     print(await get_body(request))
 
     response = await call_next(request)
     return response

await set_body(request, request.body()) -> await set_body(request, await request.body())

Looks like await should be added.

[king-peanut]

For anyone who is looking for class-based middleware:

class LoggingMiddleware(BaseHTTPMiddleware):

    def __init__(self, app):
        super().__init__(app)

    async def set_body(self, request: Request):
        receive_ = await request._receive()

        async def receive() -> Message:
            return receive_

        request._receive = receive

    async def dispatch(self, request, call_next):
        await self.set_body(request)
        body = await request.body()
        json_body = await request.json()

        print(body)
        print(json_body)

        response = await call_next(request)

        return response

Many thanks for @liukelin

[XaviTorello]

This workaround works as expected many thanks @king-peanut.

The unique condition is that this should be placed as the last middleware (the first to be loaded into the app, take care about the reverse ordering), if not it will freeze.

[Nick1994209]

If you're using StreamingResponse in your response.

    receive_ = await request._receive()

    async def receive() -> Message:
        return receive_

    request._receive = receive

Does not work =(

But you can write

async def get_request_body(request: Request) -> bytes:
    body = await request.body()

    request._receive = ReceiveProxy(receive=request.receive, cached_body=body)
    return body


@dataclasses.dataclass
class ReceiveProxy:
    """Proxy to starlette.types.Receive.__call__ with caching first receive call."""

    receive: starlette.types.Receive
    cached_body: bytes
    _is_first_call: ClassVar[bool] = True

    async def __call__(self):
        # First call will be for getting request body => returns cached result
        if self._is_first_call:
            self._is_first_call = False
            return {"type": "http.request", "body": self.cached_body, "more_body": False}

        return await self.receive()

[100gle]

Note that in higher version of Starlette(>0.27.0), this magic snippet doesn't work and an RuntimeError will be throwed:

RuntimeError: Unexpected message received: http.request

the solution is: directly await and get body:

async def get_request_body(request: Request) -> bytes:
    body = await request.body()
    return body

[Kludex]

Can I have an MRE about how you get this RuntimeError?

[CFelipezapata]

@Kludex I was having this issue, but @100gle's solution worked for me. Here's a way to reproduce the error:

from fastapi import FastAPI, Request
from starlette.types import Message

app = FastAPI()    

@app.middleware('http')
async def request_body_fix(request: Request, call_next):
    body = await request.body()
    async def receive() -> Message:
        return {"type": "http.request", "body": body}
    request._receive = receive
    return await call_next(request)


@app.post("/my_route")
async def my_route():
    print(f"Executing code inside /my_route")
    return {"message": "Hello World"}

My app used to have this code to access the body of the request in the middleware and do some logic with it. However, with the recent upgrate of fastapi to use a higher version of Starlette, this broke my app, I assume this happened to @100gle as well. It works fine for fastapi<=0.106.0 which still uses Starlette 0.27 I believe.

[Kludex]

Well... That's exactly what we fixed...

You don't need the workaround of receive() anymore...

from fastapi import FastAPI, Request
from starlette.types import Message

app = FastAPI()

@app.middleware('http')
async def request_body_fix(request: Request, call_next):
    body = await request.body()
    print(f"Body: {body}")
    return await call_next(request)


@app.post("/my_route")
async def my_route(request: Request):
    print(f"Executing code inside /my_route")
    body = await request.body()
    print(f"Body: {body}")
    return {"message": "Hello World"}

You can now read the body on the middleware, and on the endpoint, without hanging.

[shauryagoel]

@king-peanut Your solution solves the hanging issue. However, whenever I do request.json() again in the endpoint function (besides doing it in the middleware), the byte string data is read again and converted to the python dictionary again. This can cause extra latency when the payload is large.

[wulicjk]

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"})

You can add a dependent function in the router, and put the value of request.json into request.state in the dependent function. Now we consider how to get this value. Since the execution order of the program when the request comes is to execute the middleware first. Then execute the dependent function, we can get request.json from the request when the middleware gets the response

async def log_json(request: Request):
    param_json = await request.json()
    request.state.param_json = param_json

# register route
app.include_router(main_router, dependencies=[Depends(log_json)])

# in the middleware
response: StreamingResponse = await call_next(request)
    param_json = request.state.param_json

[taegyunum]

Many solutions suggested above works fine in most cases, but I think there is some problem with Mac OS docker environment.
If someone want to use in Mac OS container, this approach should work.
@CuiJianKang666 Thank you.

cf. #8534

[Kludex]

I'm locking this issue to avoid confusion.

This was solved on FastAPI 0.108.0.

See what I said here for more details.