Logging not working as expected within add_exception_handler()

[j-4ck]

I'm using a small test program (below) in order to try to integrate fastapi-problem exceptions with a logger. In this example, the logger is configured to output to stdout. You can see in the outputs (also below) that the 404 Not Found exception is handled and the correct response is created, though there is no output to stdout... Am I misunderstanding the role or usage of the "logger" variable in add_exception_handler() ? It seems they aren't being handled by the logger I specified.

Code:

# fastapi-problem version: 0.10.5
import logging
import sys
import fastapi
import uvicorn
from fastapi_problem.error import NotFoundProblem
from fastapi_problem.handler import add_exception_handler, StripExtrasPostHook

logging.getLogger("uvicorn.access").setLevel(logging.WARNING)
logging.getLogger("uvicorn.asgi").setLevel(logging.WARNING)
logging.getLogger("uvicorn.error").setLevel(logging.WARNING)
logging.getLogger("uvicorn").setLevel(logging.WARNING)
logging.getLogger("asyncio").setLevel(logging.WARNING)

logging.basicConfig(stream = sys.stdout, level = logging.DEBUG)
logger = logging.getLogger("test")
logger.info("testing")

class NotFoundError(NotFoundProblem):
    title = "Endpoint not available."
    detail = "This detail is not found!"

app = fastapi.FastAPI()
add_exception_handler(app,
					  logger = logger,
					  post_hooks = [StripExtrasPostHook(exclude_status_codes = [500], enabled = True)],
					  unhandled_wrappers = {
						  "404": NotFoundError,
						  },
					  )
@app.get("/user")
async def user():
	logger.info("Hello user")
	return "Hello user"

if __name__ == "__main__":
    uvicorn.run("problemLogging:app", host = "127.0.0.1", port = 8000, log_level = "info")

Curl requests:

curl -X "GET" "http://127.0.0.1:8000/user"
"Hello user"
curl -X "GET" "http://127.0.0.1:8000/server"
{"type":"not-found","title":"Endpoint not available.","status":404,"detail":"Not Found"}

Output:

INFO:test:testing
INFO:test:testing
INFO:test:Hello user

I am also expecting something like INFO:test:404 Error to be printed by my logger

[EdgyEdgemond]

The logger is used when a 5xx error occurs to capture the stacktrace. 4xx errors aren't logged as they are caused and fixed by user behaviour. There is (usually) no need to log the cause or a 404 etc as it is known why that has happened, the route called doesn't exist etc.

As 5XXs are often unexpected being able to trace the root cause is more viable.

[EdgyEdgemond]

If you want to add custom logging you could add a custom pre-hook

See https://nrwldev.github.io/fastapi-problem/hooks/

Also if you raise an exception in your view, you will see logs from that being caught in your logger.

[j-4ck]

Okay thank you for your quick response and clearing up my misunderstanding. Will mark as answered

[EdgyEdgemond]

No worries, thanks for using/trying my library.I'll make a note to add more details to the docs to clear up what the logger is expected to provide to end users.

[EdgyEdgemond]

Side note, detail for a Problem is provided when raised, specifying it on the class will be ignored/overridden, which is why you are not seeing it in the response.