diff --git a/src/blueapi/service/main.py b/src/blueapi/service/main.py index 432cc5455..1296bec58 100644 --- a/src/blueapi/service/main.py +++ b/src/blueapi/service/main.py @@ -594,16 +594,19 @@ def start(config: ApplicationConfig): async def log_request_details( request: Request, call_next: Callable[[Request], Awaitable[StreamingResponse]] ) -> Response: - """Middleware to log all request's host, method, path, status and request and - body""" - log = LOGGER.debug if request.url.path == "/healthz" else LOGGER.info + """Middleware to log request's host, method, path, status and request and + body + + Logs GET as debug, all else as info.""" + log = LOGGER.debug if request.method == "GET" else LOGGER.info request_body = await request.body() client = request.client or Address("Unknown", -1) log_message = f"{client.host}:{client.port} {request.method} {request.url.path}" extra = { "request_body": request_body, } - log(log_message, extra=extra) + if request.method != "GET": + log(log_message, extra=extra) response = await call_next(request) log_message += f" {response.status_code}" diff --git a/tests/unit_tests/service/test_main.py b/tests/unit_tests/service/test_main.py index 5a48a9dd0..93df36266 100644 --- a/tests/unit_tests/service/test_main.py +++ b/tests/unit_tests/service/test_main.py @@ -30,31 +30,37 @@ async def root(): assert response.headers["X-BlueAPI-VERSION"] == __version__ -@pytest.mark.parametrize("path,level", [("/", "info"), ("/healthz", "debug")]) -async def test_log_request_details(path: str, level: str): - with mock.patch("blueapi.service.main.LOGGER") as logger: - app = FastAPI() - app.middleware("http")(log_request_details) +@pytest.fixture +def logging_server(): + app = FastAPI() + app.middleware("http")(log_request_details) + + @app.post("/") + async def root(): + return {"message": "Hello World"} - @app.post(path) - async def root(): - return {"message": "Hello World"} + @app.get("/healthz") + async def health(): + return {"health": "good"} - client = TestClient(app) - response = client.post(path, content="foo") + return TestClient(app) + + +async def test_post_request_logs_at_info(logging_server: TestClient): + with mock.patch("blueapi.service.main.LOGGER") as logger: + response = logging_server.post("/", content="foo") assert response.status_code == 200 - log_level = getattr(logger, level) - log_level.assert_has_calls( + logger.info.assert_has_calls( [ call( - f"testclient:50000 POST {path}", + "testclient:50000 POST /", extra={ "request_body": b"foo", }, ), call( - f"testclient:50000 POST {path} 200", + "testclient:50000 POST / 200", extra={ "request_body": b"foo", }, @@ -63,6 +69,21 @@ async def root(): ) +async def test_get_request_logs_at_debug(logging_server: TestClient): + with mock.patch("blueapi.service.main.LOGGER") as logger: + response = logging_server.get("/healthz") + + assert response.status_code == 200 + logger.debug.assert_has_calls( + [ + call( + "testclient:50000 GET /healthz 200", + extra={"request_body": b""}, + ), + ] + ) + + @pytest.mark.parametrize( "headers, expected_headers", [