feat: Add Status Code and Request and Response Bodies to Logs

src/blueapi/service/main.py

@@ -16,8 +16,9 @@
     Response,
     status,
 )
+from fastapi.datastructures import Address
 from fastapi.middleware.cors import CORSMiddleware
-from fastapi.responses import RedirectResponse
+from fastapi.responses import RedirectResponse, StreamingResponse
 from fastapi.security import OAuth2AuthorizationCodeBearer
 from observability_utils.tracing import (
     add_span_attributes,
@@ -576,14 +577,25 @@ async def add_api_version_header(
 
 
 async def log_request_details(
-    request: Request, call_next: Callable[[Request], Awaitable[Response]]
+    request: Request, call_next: Callable[[Request], Awaitable[StreamingResponse]]
 ) -> Response:
-    msg = f"method: {request.method} url: {request.url} body: {await request.body()}"
+    """Middleware to log all request's host, method, path, status and request and
+    body"""
+    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,
+    }
+    LOGGER.debug(log_message, extra=extra)
+
+    response = await call_next(request)
+    log_message += f" {response.status_code}"
     if request.url.path == "/healthz":
-        LOGGER.debug(msg)
+        LOGGER.debug(log_message, extra=extra)
     else:
-        LOGGER.info(msg)
-    response = await call_next(request)
+        LOGGER.info(log_message, extra=extra)
+
     return response
 
 

tests/unit_tests/service/test_main.py

@@ -13,16 +13,26 @@ async def test_log_request_details():
         app = FastAPI()
         app.middleware("http")(log_request_details)
 
-        @app.get("/")
+        @app.post("/")
         async def root():
             return {"message": "Hello World"}
 
         client = TestClient(app)
-        response = client.get("/")
+        response = client.post("/", content="foo")
 
         assert response.status_code == 200
+        logger.debug.assert_called_once_with(
+            "testclient:50000 POST /",
+            extra={
+                "request_body": b"foo",
+            },
+        )
+
         logger.info.assert_called_once_with(
-            "method: GET url: http://testserver/ body: b''"
+            "testclient:50000 POST / 200",
+            extra={
+                "request_body": b"foo",
+            },
         )