17 — Observability

Implementation: rag/telemetry.py, rag/metrics.py, rag/instrumentation.py, adapters/prometheus.py, infra/docker/{prometheus,grafana,tempo,otel}/. Tests: tests/test_observability.py.

Signal table

Signal	Instrumentation	Backend	Purpose
Metrics	`prometheus_client` via `adapters/prometheus.py`, exposed at `GET /metrics`	Prometheus (scrape 15 s)	Request rate/latency, decisions, abstentions, provider failures
Traces	OpenTelemetry SDK, OTLP/HTTP	OTel Collector → Tempo	Per-request spans with per-stage children
Logs	Python `logging` to stdout, uvicorn defaults	`docker logs` only	Ad-hoc debugging
Dashboards	Provisioned JSON	Grafana	`duocthu-observability`
Health	`/health`, `/ready`	Compose/K8s probes + the deploy smoke test	Liveness/readiness
Alerting	—	—	Not found

Both metrics and tracing are optional and degrade to no-ops: a missing prometheus_client yields None metrics rather than a service that will not start ("observability is not a precondition for answering"), and missing OpenTelemetry packages or OTEL_ENABLED=false yield a no-op tracer.

Metrics

Names are defined in rag/metrics.py so, as the docstring puts it, "the numbers on a dashboard are the numbers the domain actually decided".

Metric	Type	Labels	Incremented in
`duocthu_requests_total`	counter	`method`, `route`, `status` (class)	`main.py` middleware
`duocthu_request_duration_seconds`	histogram	`method`, `route`, `status`	`main.py` middleware
`duocthu_stage_duration_seconds`	histogram	`stage`, `outcome`	`telemetry.stage()`
`duocthu_decision_total`	counter	`decision`, `reason`	`routers/rag.py`
`duocthu_retrieval_route_total`	counter	`route`	`InstrumentedRetrievalService`
`duocthu_abstention_total`	counter	`reason`	`answer.py`
`duocthu_generation_rejected_total`	counter	`reason`	`answer.py`
`duocthu_generation_served_total`	counter	—	`answer.py`
`duocthu_answer_extractive_total`	counter	—	`answer.py` (no-generator mode)
`duocthu_clarify_asked_total`	counter	`reason`	`InstrumentedRagAgent`
`duocthu_provider_failure_total`	counter	`provider`, `operation`, `reason`	`Instrumented{Generator,Embedder,Reranker}`, retrieval
`duocthu_trace_write_failed_total`	counter	—	`routers/rag.py`

duocthu_generation_rejected_total is called out in the module docstring as the one that matters: it is the measured form of the claim that the answer layer cannot state a figure the book does not.

Registered but never incremented

duocthu_loop_retrieval_rounds_total, duocthu_loop_refined_total, duocthu_loop_repaired_total, duocthu_followup_inherited_total. Verified by grep: their only references outside rag/metrics.py are the registration and help-text tables in adapters/prometheus.py. They are leftovers of the ADR 0007 loop design that ADR 0008 replaced, and they will always report zero.

Cardinality control

Every label is a bounded vocabulary. _route_label in main.py maps any unrecognised path to the literal "other", and status is a class (2xx/4xx/5xx), not a code. adapters/prometheus.py normalises stage/provider/reason values. Without this, a caller could mint unbounded time series by varying the URL.

Tracing

rag/telemetry.py configures one OTLP tracer provider, with ParentBased(TraceIdRatioBased(OTEL_SAMPLE_RATIO)) and a BatchSpanProcessor. If a provider was already installed (by a host or a test) it is reused rather than replaced.

Span structure for one request:

SERVER  {METHOD} {route}                       ← main.py middleware, extracts traceparent
├── rag.stage.receive
├── rag.stage.context                          ← RagAgent._get_history
├── rag.stage.understanding                    ← InstrumentedQueryUnderstander
│   └── provider.bedrock_converse.understand
├── rag.stage.routing                          ← RagAgent._route
│   ├── rag.stage.retrieval
│   │   ├── rag.stage.rerank
│   │   └── rag.stage.evidence
│   ├── rag.stage.generation
│   │   └── provider.bedrock_converse.generate
│   ├── rag.stage.grounding                    ← @traced_stage on grounding.verify
│   └── rag.stage.entailment
│       └── provider.bedrock_converse.entailment
├── rag.stage.persistence
└── rag.stage.response

InstrumentedGenerator derives the dependency-span operation name from the current stage (understanding → understand, generation → generate, entailment → entailment), so all three Bedrock calls are distinguishable despite going through one adapter.

stage() also records duocthu_stage_duration_seconds and marks duocthu.outcome as ok / error / cancelled — which answers the "trace has no per-stage timing" gap noted in the earlier pipeline audit.

Span attributes

duocthu.correlation_id, duocthu.decision, duocthu.reason, duocthu.citation_count, duocthu.generated, duocthu.persisted_trace_id, duocthu.evidence_count, duocthu.turn_type, duocthu.needs_clarify, duocthu.system_error, duocthu.http.status_class, duocthu.duration_ms, duocthu.stage, duocthu.outcome, duocthu.provider, duocthu.operation.

annotate_current_span silently drops any value that is not str/bool/ int/float, so a stray object cannot break export.

Correlation

Three identifiers, joinable:

Id	Origin	Carried in
`X-Correlation-ID`	Client, or generated; validated by regex	Request header, response header, `rag_retrieval_trace.correlation_id`, span attribute
OTel trace id	Sampler	`X-Trace-ID` response header, `rag_retrieval_trace.otel_trace_id`, Tempo
`trace_id` (application)	UUID per answer	Response body, `rag_retrieval_trace.trace_id`, `rag_answer_feedback.trace_id`

migrations/003 adds partial indexes on the first two, so a support request carrying either header can be looked up.

Propagation is stored as a context var (ContextVar), which works across FastAPI's async middleware and its sync thread-pool endpoint — the module docstring names that as the reason for the design.

Deployed stack

flowchart LR
    AI["ai-service<br/>OTEL_ENABLED=true"]
    OC["otel-collector 0.123.0<br/>memory_limiter + batch"]
    TP["tempo 2.7.2"]
    PR["prometheus v3.3.0<br/>scrape ai-service:8000/metrics"]
    GF["grafana 11.5.2<br/>127.0.0.1:3002"]
    CD["caddy → /grafana/*"]
    U[Operator]

    AI -->|"OTLP/HTTP :4318"| OC -->|"OTLP/gRPC tempo:4317"| TP
    PR -->|scrape 15s| AI
    GF --> PR
    GF --> TP
    U -->|https://realvuxbaro.me/grafana/| CD --> GF

Datasources are provisioned with fixed UIDs prometheus and tempo (infra/docker/grafana/provisioning/datasources/prometheus.yml), and the dashboard duocthu-observability is provisioned from infra/docker/grafana/dashboards/duocthu-grounding.json. Exemplar storage is enabled on Prometheus (--enable-feature=exemplar-storage).

What the deploy pipeline actually verifies

.github/workflows/deploy.yml does not just start the stack — it asserts it:

prometheus:9090/-/ready, tempo:3200/ready (retried 12×5 s), grafana:3000/api/health;
both Grafana datasources exist by UID, authenticated as admin;
the dashboard duocthu-observability exists;
https://realvuxbaro.me/grafana/login is reachable;
a real query is issued with a generated X-Correlation-ID, the returned X-Trace-ID is asserted to match ^[0-9a-f]{32}$, then after 20 s duocthu_requests_total must be present in Prometheus and the exact trace id must be retrievable from tempo:3200/api/traces/<id> (retried 12×5 s).

That last assertion is the strongest evidence in the repository that tracing works end to end in production.

Gaps

No alerting. No Alertmanager, no Prometheus rule files, no Grafana alert rules in the provisioning directory.
No log aggregation. No Loki, no Promtail, no structured/JSON logging. Logs are reachable only via docker logs, and the level choices are odd — agent.py logs ordinary per-turn timings at warning because uvicorn's default config does not wire handlers onto the root logger.
No SLOs, no error budget, no burn-rate rules.
web is not instrumented at all — no metrics, no traces, no structured logs. It only forwards traceparent.
No Prometheus retention flag in the Compose overlay (the Helm values set 7 d; Compose relies on the image default).
No RED/USE dashboard beyond the single provisioned one; its panel set was not audited in this pass.

8.7 KiB Raw Blame History Unescape Escape