-
First Check
Commit to Help
Example Codeimport logging
import sys
import time
import uvicorn
from fastapi import FastAPI, Request
from fastapi.responses import Response
logger = logging.getLogger()
logger.setLevel(logging.DEBUG)
handler = logging.StreamHandler(sys.stdout)
handler.setLevel(logging.DEBUG)
formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s")
handler.setFormatter(formatter)
logger.addHandler(handler)
app = FastAPI()
@app.get("/")
def index():
raise ValueError("Crash.")
return "Test."
async def log_request(request: Request, call_next):
try:
response = await call_next(request)
except Exception:
logger.error("Middleware observed exception.")
logger.info("Returning response.")
return response
async def log_exception(request: Request, exc: Exception):
logger.error(f"Encountered exception {exc}.")
return Response(status_code=503, content="test")
if __name__ == "__main__":
app.exception_handler(Exception)(log_exception)
app.middleware("http")(log_request)
uvicorn.run(app, host="0.0.0.0", port=8000)DescriptionI have this use case where I want to log the duration of all requests, this includes requests which crash the route handler function. For this I introduced a request logging middleware. From my observations once a exception handler is triggered, all middlewares are bypassed. So even if the exception handler returns an Response object there is no way to react to it in the middleware. Is my understanding of this correct? And is this a bug or a feature? (Based on the answer to do this I will submit an MR which adds this to the Middleware documentation) Operating SystemLinux Operating System DetailsNo response FastAPI Version0.70.1 Python VersionPython 3.10.0 Additional ContextNo response |
Beta Was this translation helpful? Give feedback.
Replies: 5 comments 5 replies
-
|
When I run your sample code I get the following Which you would expect since If I correct for the error by refactoring your function to async def log_request(request: Request, call_next):
response = None
try:
response = await call_next(request)
except Exception:
logger.error("Middleware observed exception.")
response = Response(status_code=200, content="Caught in the middleware")
logger.info("Returning response.")
return responseI get the expected 200 with the logged This is with |
Beta Was this translation helpful? Give feedback.
-
|
@jgould22 Thank you very much! After upgrading to |
Beta Was this translation helpful? Give feedback.
-
|
HI guys! I have a question related to this one: what if I want to log the response body size that is returned from the exception handler? If |
Beta Was this translation helpful? Give feedback.
-
|
I don't think you can. The exception occurs while building the |
Beta Was this translation helpful? Give feedback.
-
|
I also encountered this problem. I added a Update: |
Beta Was this translation helpful? Give feedback.
-
|
Can you provide example code? An alternative to the middleware may be Custom Request and APIRoute class. I use it this way to log every request and response, including errors, if it helps. |
Beta Was this translation helpful? Give feedback.
-
Sure, here is a minimal implementation with my test results: from datetime import datetime
from fastapi import APIRouter, FastAPI, Request, status
from fastapi.responses import JSONResponse
from loguru import logger
router = APIRouter()
def add_exception_handlers(app: FastAPI) -> None:
async def value_error_handler(request: Request, exc: ValueError):
logger.error(f"In handler: `ValueError` captured!" f"\n\t{exc}")
return JSONResponse(
content={"message": f"Failed! Detail: Internal ValueError!"},
status_code=status.HTTP_400_BAD_REQUEST,
)
async def any_exception_handler(request: Request, exc: Exception):
logger.error(
f"In handler: Exception `{type(exc).__name__}` captured!" f"\n\t{exc}"
)
return JSONResponse(
content={
"message": f"Failed! Detail: Internal error occurred!",
},
status_code=status.HTTP_400_BAD_REQUEST,
)
app.add_exception_handler(ValueError, value_error_handler)
app.add_exception_handler(Exception, any_exception_handler)
return
async def mw_log_request(request: Request, call_next):
start_at = datetime.now()
try:
response = await call_next(request)
ended_at = datetime.now()
except Exception as e:
response = None
ended_at = datetime.now()
logger.error(f"In middleware: Error caught! Type: {type(e)} Detail: {e}")
raise e from None
finally:
logger.info(
f"request done, cost: {(ended_at - start_at).total_seconds():.2f} second(s)"
)
return response or JSONResponse({"msg": "Failed!"})
@router.get("/exception")
def test():
raise Exception
return {"Hello": "World"}
@router.get("/value_error")
def test2():
raise ValueError
return {"Hello": "World too!"}
def create_app():
app = FastAPI()
app.include_router(router)
app.middleware("http")(mw_log_request)
add_exception_handlers(app)
return app
app = create_app()send requests at another terminal: Update: |
Beta Was this translation helpful? Give feedback.
-
|
I made it work using See codefrom datetime import datetime
from fastapi import APIRouter, FastAPI, Request, status
from fastapi.exceptions import RequestValidationError
from fastapi.responses import JSONResponse
from loguru import logger
router = APIRouter()
def add_exception_handlers(app: FastAPI) -> None:
async def value_error_handler(request: Request, exc: RequestValidationError):
logger.error(f"In handler: `ValueError` captured!" f"\n\t{exc}")
return JSONResponse(
content={"message": f"Failed! Detail: Internal ValueError!"},
status_code=status.HTTP_400_BAD_REQUEST,
)
async def any_exception_handler(request: Request, exc: Exception):
logger.error(
f"In handler: Exception `{type(exc).__name__}` captured!" f"\n\t{exc}"
)
return JSONResponse(
content={
"message": f"Failed! Detail: Internal error occurred!",
},
status_code=status.HTTP_400_BAD_REQUEST,
)
app.add_exception_handler(RequestValidationError, value_error_handler)
app.add_exception_handler(Exception, any_exception_handler)
return
async def mw_log_request(request: Request, call_next):
start_at = datetime.now()
try:
response = await call_next(request)
ended_at = datetime.now()
except Exception as e:
response = None
ended_at = datetime.now()
logger.error(f"In middleware: Error caught! Type: {type(e)} Detail: {e}")
raise e from None
finally:
logger.info(
f"request done, cost: {(ended_at - start_at).total_seconds():.2f} second(s)"
)
return response or JSONResponse({"msg": "Failed!"})
@router.get("/exception")
def test():
raise Exception
return {"Hello": "World"}
@router.get("/value_error")
def test2():
raise ValueError
return {"Hello": "World too!"}
def create_app():
app = FastAPI()
app.include_router(router)
app.middleware("http")(mw_log_request)
add_exception_handlers(app)
return app
app = create_app()Output: $ uvicorn --reload api:app
INFO: Will watch for changes in these directories: ['/tmp/fastapi']
INFO: Uvicorn running on http://127.0.0.1:8000 (Press CTRL+C to quit)
INFO: Started reloader process [102981] using StatReload
INFO: Started server process [102983]
INFO: Waiting for application startup.
INFO: Application startup complete.
2024-08-28 15:15:19.160 | ERROR | api:mw_log_request:43 - In middleware: Error caught! Type: <class 'Exception'> Detail:
2024-08-28 15:15:19.160 | INFO | api:mw_log_request:46 - request done, cost: 0.00 second(s)
2024-08-28 15:15:19.162 | ERROR | api:any_exception_handler:20 - In handler: Exception `Exception` captured!
INFO: 127.0.0.1:42082 - "GET /exception HTTP/1.1" 400 Bad Request
2024-08-28 15:15:21.207 | ERROR | api:mw_log_request:43 - In middleware: Error caught! Type: <class 'ValueError'> Detail:
2024-08-28 15:15:21.207 | INFO | api:mw_log_request:46 - request done, cost: 0.00 second(s)
2024-08-28 15:15:21.208 | ERROR | api:any_exception_handler:20 - In handler: Exception `ValueError` captured!
INFO: 127.0.0.1:42090 - "GET /value_error HTTP/1.1" 400 Bad RequestNot sure why yet, maybe But still, you may want to look Custom Request and APIRoute class (and this gist). I found |
Beta Was this translation helpful? Give feedback.
-
|
Hey guys, after more than two months, I seem to have found an elegant solution to this problem, which seems to be caused by the disharmonious between starlette and fastapi. To do this, we need to do three things:
from datetime import datetime
from random import random
from time import sleep
from fastapi import APIRouter, FastAPI, Request, Response, status
from fastapi.responses import JSONResponse
from loguru import logger
from starlette.middleware import base
router = APIRouter()
def handle_exceptions(exc: Exception, return_as_response: bool = False):
logger.error(f"Caught exception: {exc!r}")
match exc:
case ValueError() as exc:
detail = str(exc)
status_code = status.HTTP_422_UNPROCESSABLE_ENTITY
case Exception():
detail = "Unexpected internal error, please contact the developers."
status_code = status.HTTP_500_INTERNAL_SERVER_ERROR
if not return_as_response:
return detail
return JSONResponse(
{
"message": "failed",
"detail": detail,
},
media_type="application/json",
status_code=status_code,
)
class ExceptionHandlerMiddleware(base.BaseHTTPMiddleware):
async def dispatch(
self, request: Request, handler: base.RequestResponseEndpoint
) -> Response:
start_at = datetime.now()
try:
response = await handler(request)
return response
except Exception as exc:
return handle_exceptions(exc, True)
finally:
ended_at = datetime.now()
logger.info(
f"request done, cost: {(ended_at - start_at).total_seconds():.2f} second(s)"
)
@router.get("/exception")
def test():
sleep(random() * 3)
raise Exception("We are on the verge of bankruptcy!")
return {"Hello": "World"}
@router.get("/value_error")
def test2():
sleep(random() * 3)
raise ValueError("Something is wrong.")
return {"Hello": "World too!"}
def create_app():
app = FastAPI()
app.include_router(router)
app.add_middleware(ExceptionHandlerMiddleware)
return app
app = create_app()Launch app: gunicorn --worker-class uvicorn.workers.UvicornWorker test:appOn client side: # curl -i 127.0.0.1:8000/value_error
HTTP/1.1 422 Unprocessable Entity
date: Tue, 29 Oct 2024 10:47:00 GMT
server: uvicorn
content-length: 51
content-type: application/json
{"message":"failed","detail":"Something is wrong."}
# curl url -i 127.0.0.1:8000/exception
HTTP/1.1 500 Internal Server Error
date: Tue, 29 Oct 2024 10:47:25 GMT
server: uvicorn
content-length: 89
content-type: application/json
{"message":"failed","detail":"Unexpected internal error, please contact the developers."}On server side: 2024-10-29 18:47:01.789 | ERROR | test2:handle_exceptions:14 - Caught exception: ValueError('Something is wrong.')
2024-10-29 18:47:01.789 | INFO | test2:dispatch:46 - request done, cost: 0.32 second(s)
2024-10-29 18:47:27.852 | ERROR | test2:handle_exceptions:14 - Caught exception: Exception('We are on the verge of bankruptcy!')
2024-10-29 18:47:27.852 | INFO | test2:dispatch:46 - request done, cost: 2.12 second(s) |
Beta Was this translation helpful? Give feedback.
-
|
Inspired by Kludex/starlette#891 |
Beta Was this translation helpful? Give feedback.
When I run your sample code I get the following