add requests logging

app.py

@@ -3,14 +3,16 @@ import signal
 import os
 import time
 import asyncio
-from typing import Optional, Dict, List
+from typing import Optional, Dict, List, Any
 from dataclasses import dataclass, field
 from collections import OrderedDict
 from datetime import datetime, timedelta
 import hashlib
+import json
+import uuid
 
 import aiohttp
-from fastapi import FastAPI, HTTPException, BackgroundTasks
+from fastapi import FastAPI, HTTPException, BackgroundTasks, Request
 from fastapi.openapi.utils import get_openapi
 from pydantic import BaseModel, Field
 from duckduckgo_search import DDGS
@@ -108,6 +110,8 @@ BASE_PORT = int(os.getenv("BASE_PORT", "8080"))
 PRELOAD_MODELS = os.getenv("PRELOAD_MODELS", "").split(",") if os.getenv("PRELOAD_MODELS") else []
 WEB_SEARCH_CACHE_TTL = int(os.getenv("WEB_SEARCH_CACHE_TTL", "3600"))  # 1 hour
 REQUEST_TIMEOUT = int(os.getenv("REQUEST_TIMEOUT", "300"))  # 5 minutes
+LOG_REQUEST_BODY = os.getenv("LOG_REQUEST_BODY", "1") == "1"
+LOG_REQUEST_BODY_MAX_CHARS = int(os.getenv("LOG_REQUEST_BODY_MAX_CHARS", "2000"))
 
 
 @dataclass
@@ -361,6 +365,84 @@ metrics = PerformanceMetrics()
 # HTTP session for connection pooling (will be initialized in startup)
 http_session: Optional[aiohttp.ClientSession] = None
 
+SENSITIVE_HEADERS = {"authorization", "proxy-authorization", "x-api-key", "api-key"}
+SENSITIVE_FIELDS = {"authorization", "api_key", "api-key", "password", "token"}
+
+
+def _redact_headers(headers: Dict[str, str]) -> Dict[str, str]:
+    """Redact sensitive headers before logging."""
+    redacted = {}
+    for key, value in headers.items():
+        if key.lower() in SENSITIVE_HEADERS:
+            redacted[key] = "[redacted]"
+        else:
+            redacted[key] = value
+    return redacted
+
+
+def _redact_json(obj: Any) -> Any:
+    """Redact sensitive fields in JSON-like structures."""
+    if isinstance(obj, dict):
+        redacted = {}
+        for key, value in obj.items():
+            if str(key).lower() in SENSITIVE_FIELDS:
+                redacted[key] = "[redacted]"
+            else:
+                redacted[key] = _redact_json(value)
+        return redacted
+    if isinstance(obj, list):
+        return [_redact_json(item) for item in obj]
+    return obj
+
+
+def _format_body_for_log(content_type: str, body: bytes) -> str:
+    """Format request body for logging with size limits and redaction."""
+    if not body:
+        return ""
+
+    text_preview: str
+    if "application/json" in (content_type or ""):
+        try:
+            parsed = json.loads(body.decode("utf-8"))
+            redacted = _redact_json(parsed)
+            text_preview = json.dumps(redacted, ensure_ascii=True)
+        except Exception:
+            text_preview = body.decode("utf-8", errors="replace")
+    else:
+        text_preview = body.decode("utf-8", errors="replace")
+
+    if len(text_preview) > LOG_REQUEST_BODY_MAX_CHARS:
+        text_preview = text_preview[:LOG_REQUEST_BODY_MAX_CHARS] + "...[truncated]"
+    return text_preview
+
+
+@app.middleware("http")
+async def log_received_request(request: Request, call_next):
+    """Log incoming requests and responses with basic metadata."""
+    request_id = uuid.uuid4().hex[:12]
+    start = time.perf_counter()
+
+    body_text = ""
+    if LOG_REQUEST_BODY:
+        body_bytes = await request.body()
+        body_text = _format_body_for_log(request.headers.get("content-type", ""), body_bytes)
+
+    headers = _redact_headers(dict(request.headers))
+    client_host = request.client.host if request.client else "-"
+    query = f"?{request.url.query}" if request.url.query else ""
+
+    logger.info(
+        f"➡️  {request_id} {request.method} {request.url.path}{query} "
+        f"from {client_host} ua={headers.get('user-agent', '-')}"
+    )
+    if body_text:
+        logger.info(f"   body={body_text}")
+
+    response = await call_next(request)
+    elapsed_ms = (time.perf_counter() - start) * 1000
+    logger.info(f"⬅️  {request_id} {response.status_code} {elapsed_ms:.1f}ms")
+    return response
+
 
 class ModelSwitchRequest(BaseModel):
     """Request to switch the active LLM model."""