Add observability: request-id middleware, structured JSON logging, pr…

app/logging_config.py

@@ -0,0 +1,32 @@
+import logging
+import sys
+import json
+from datetime import datetime
+
+class JsonFormatter(logging.Formatter):
+    def format(self, record: logging.LogRecord) -> str:
+        payload = {
+            "ts": datetime.utcfromtimestamp(record.created).isoformat() + "Z",
+            "level": record.levelname,
+            "logger": record.name,
+            "msg": record.getMessage(),
+        }
+        # Include extra fields if present
+        if hasattr(record, "request_id"):
+            payload["request_id"] = record.request_id
+        if hasattr(record, "extra") and isinstance(record.extra, dict):
+            payload.update(record.extra)
+        if record.exc_info:
+            payload["exc_info"] = self.formatException(record.exc_info)
+        return json.dumps(payload)
+
+
+def configure_logging(level=logging.INFO):
+    handler = logging.StreamHandler(sys.stdout)
+    handler.setFormatter(JsonFormatter())
+    root = logging.getLogger()
+    root.setLevel(level)
+    # Remove existing handlers to avoid duplicates
+    if root.handlers:
+        root.handlers = []
+    root.addHandler(handler)

app/metrics.py

@@ -0,0 +1,15 @@
+from prometheus_client import Counter, Histogram, generate_latest, CONTENT_TYPE_LATEST
+from fastapi import Response
+
+# Counters
+WEBHOOK_REQUESTS = Counter("webhook_requests_total", "Webhook requests received", ["provider", "status"])
+SIGNATURE_FAILURES = Counter("signature_validation_failures_total", "Signature validation failures", ["provider"])
+LLM_CALLS = Counter("llm_calls_total", "OpenAI/LLM calls", ["success"])
+MESSAGES_SENT = Counter("messages_sent_total", "Messages sent via provider", ["success"])
+
+WEBHOOK_LATENCY = Histogram("webhook_latency_seconds", "Webhook processing latency")
+
+
+def metrics_endpoint() -> Response:
+    data = generate_latest()
+    return Response(content=data, media_type=CONTENT_TYPE_LATEST)

app/middleware.py

@@ -0,0 +1,37 @@
+import time
+import logging
+import uuid
+from starlette.types import ASGIApp, Receive, Scope, Send
+from starlette.requests import Request
+from starlette.responses import Response
+from typing import Callable
+
+logger = logging.getLogger(__name__)
+
+class RequestIDMiddleware:
+    """Middleware to attach or generate a request id and measure request time.
+
+    Sets `request.state.request_id` and adds it to log records via structured logging helper.
+    """
+    def __init__(self, app: ASGIApp, header_name: str = "X-Request-Id"):
+        self.app = app
+        self.header_name = header_name
+
+    async def __call__(self, scope: Scope, receive: Receive, send: Send) -> None:
+        if scope["type"] != "http":
+            await self.app(scope, receive, send)
+            return
+
+        request = Request(scope, receive=receive)
+        request_id = request.headers.get(self.header_name) or str(uuid.uuid4())
+        scope.setdefault("extensions", {})["request_id"] = request_id
+        scope.setdefault("state", type("S", (), {})())
+        scope["state"] = getattr(scope, "state")
+        scope["state"].request_id = request_id
+
+        start = time.time()
+        async def send_wrapper(message):
+            await send(message)
+        await self.app(scope, receive, send_wrapper)
+        duration = time.time() - start
+        logger.info("request.completed", extra={"request_id": request_id, "path": scope.get("path"), "method": scope.get("method"), "duration": duration})

docs/observability.md

@@ -0,0 +1,34 @@
+# Observability notes
+
+This doc explains how observability is wired into the app and how to run metrics locally.
+
+What was added
+
+- RequestIDMiddleware (app.middleware.RequestIDMiddleware): generates or forwards X-Request-Id and logs request completion with duration.
+- Structured JSON logging (app.logging_config.configure_logging) with a simple JSON formatter.
+- Prometheus metrics (app.metrics) exposing basic counters and a /metrics endpoint.
+
+How to enable and run locally
+
+1. Install extra requirements:
+   pip install prometheus_client
+
+2. Start the app (example):
+   uvicorn app.main:app --reload --port 8000
+
+3. Hit /metrics to see counters:
+   curl http://localhost:8000/metrics
+
+Instrumentation points
+
+- WEBHOOK_REQUESTS.labels(provider, status).inc()
+- SIGNATURE_FAILURES.labels(provider).inc()
+- LLM_CALLS.labels(success="true"/"false").inc()
+- MESSAGES_SENT.labels(success="true"/"false").inc()
+
+Notes
+
+- This is a lightweight observability scaffold. For production consider:
+  - Using OpenTelemetry for distributed tracing
+  - Pushing metrics to a pushgateway or remote write pipeline
+  - Adding logs correlation in external systems (e.g., linking Sentry events to request_id)

requirements-observability.txt

@@ -0,0 +1,3 @@
+prometheus_client
+python-json-logger
+sentry-sdk

tests/test_observability.py

@@ -0,0 +1,14 @@
+import pytest
+from starlette.testclient import TestClient
+from app.main import app
+
+
+@pytest.fixture()
+def client():
+    return TestClient(app)
+
+
+def test_metrics_endpoint(client):
+    r = client.get("/metrics")
+    assert r.status_code == 200
+    assert "webhook_requests_total" in r.text