middleware causes exceptions to not be raised/handled silently

[Kludex]

Discussed in #1976

^{Originally posted by fraser-langton December 6, 2022}
From issue in FastAPI - issue was said to be from starlette

Was initially noticed in FastAPI 0.74.0, was fixed after 0.79.0 but has since regressed (FastAPI 0.88.0 it isn't working)

When exceptions are raised on a subapp, the exceptions are not propagated all the way to see in console
In the example code
/info raises an exception and the full stacktrace is seen in console
/private/info does not raise the exception and only INFO: 127.0.0.1:56308 - "GET /info HTTP/1.1" 500 Internal Server Error is shown in console

import uvicorn
from fastapi import FastAPI
from starlette.middleware.base import BaseHTTPMiddleware


app = FastAPI()


@app.get("/info")
def info():
    # raises Exception as expected, the traceback is seen in console
    raise Exception


private_api = FastAPI()


@private_api.get("/info")
def info():
    # exception is handled silently, no traceback is seen in console
    raise Exception


app.mount("/private", private_api)


class Middleware(BaseHTTPMiddleware):

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


app.add_middleware(Middleware)  # when this is removed, the exceptions are raised for all routes


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

[Kludex]

Probably introduced by #1715, if not... Maybe #1649?

cc @adriangb

[Kludex]

It was none of those PRs.

This was cased by #1609. Solution on #1940.

[odelmarcelle]

I'm experiencing this issue as well since the upgrade to starlette >= 0.28. I suspect this is linked to #2026?

I just ran the example above for those two cases:

• starlette 0.36.3, fastapi 0.109.2: silently fails and only prints INFO: 127.0.0.1:51560 - "GET /private/info HTTP/1.1" 500 Internal Server Error to the console
• starlette 0.27.0, fastapi 0.104.1: prints full traceback INFO: 127.0.0.1:52001 - "GET /info HTTP/1.1" 500 Internal Server Error, ERROR: Exception in ASGI application, Traceback (most recent call last): ...

I note that in the second case, the INFO logger does not show the full path (/private/info). I'm not sure why, but I was for sure sending a request to /private/info.