From ea980476f39170d610aeedc973ac30a78bea99d9 Mon Sep 17 00:00:00 2001 From: Fredrick Onyango Date: Sat, 6 Jun 2026 23:00:03 +0300 Subject: [PATCH] Add observability: request-id middleware, structured JSON logging, prometheus metrics and docs/tests --- app/logging_config.py | 32 +++++++++++++++++++++++++++++ app/metrics.py | 15 ++++++++++++++ app/middleware.py | 37 ++++++++++++++++++++++++++++++++++ docs/observability.md | 34 +++++++++++++++++++++++++++++++ requirements-observability.txt | 3 +++ tests/test_observability.py | 14 +++++++++++++ 6 files changed, 135 insertions(+) create mode 100644 app/logging_config.py create mode 100644 app/metrics.py create mode 100644 app/middleware.py create mode 100644 docs/observability.md create mode 100644 requirements-observability.txt create mode 100644 tests/test_observability.py diff --git a/app/logging_config.py b/app/logging_config.py new file mode 100644 index 0000000..e463290 --- /dev/null +++ b/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) diff --git a/app/metrics.py b/app/metrics.py new file mode 100644 index 0000000..c08cae0 --- /dev/null +++ b/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) diff --git a/app/middleware.py b/app/middleware.py new file mode 100644 index 0000000..e2dda83 --- /dev/null +++ b/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}) diff --git a/docs/observability.md b/docs/observability.md new file mode 100644 index 0000000..e303f91 --- /dev/null +++ b/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) diff --git a/requirements-observability.txt b/requirements-observability.txt new file mode 100644 index 0000000..c6adf05 --- /dev/null +++ b/requirements-observability.txt @@ -0,0 +1,3 @@ +prometheus_client +python-json-logger +sentry-sdk diff --git a/tests/test_observability.py b/tests/test_observability.py new file mode 100644 index 0000000..8c17654 --- /dev/null +++ b/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