feat: structured logs, Prometheus /metrics, tracing, rich /health (#21)

[leo-aa88]

Closes #21

Self-observability so consumers can see when raglogs itself is slow or degraded.

• JSON structlog with request_id + scope (contextvars); X-Request-Id echoed (401s included)
• GET /metrics (Prometheus text, auth-exempt) for ingest/query/LLM/breaker/queue
• OpenTelemetry spans ingest → cluster → explain; traceparent + X-Trace-Id headers (G7 body unchanged)
• /health adds llm {provider, status}; existing ok/degraded rules kept
• Default OTEL exporter none; optional OTEL_EXPORTER_OTLP_ENDPOINT; OTEL_SDK_DISABLED=true skips SDK

Metrics

• raglogs_ingest_duration_seconds
• raglogs_ingest_lines_total{result}
• raglogs_ingest_request_duration_seconds
• raglogs_cluster_count
• raglogs_query_request_duration_seconds{endpoint}
• raglogs_llm_request_duration_seconds
• raglogs_llm_fallback_total
• raglogs_llm_estimated_tokens_total
• raglogs_llm_breaker_state
• raglogs_worker_queue_depth

  

[cursor]

Bugbot is not enabled for your account, so this pull request was not reviewed.

Enable Bugbot in the Cursor dashboard to get automatic reviews on future PRs.

[cursor]

Review — PR #49 (G12 self-observability)

Checked origin/main...origin/cursor/self-observability-1cc6 against issue #21. python -m pytest tests/unit/ → 737 passed. Ruff on touched files → clean.

Acceptance that holds: /metrics is auth- and rate-limit-exempt; G7 query bodies are unchanged (trace ids on traceparent / X-Trace-Id only); /health still returns status==ok when DB is up and the breaker is closed; OTEL defaults to no exporter; LLM/cost proxy, fallback, breaker, and queue metrics exist; requirements.txt includes the new deps.

Must-fix

(None)

Should-fix

1. src/observability/metrics.py:177-178 + src/observability/middleware.py:64,209-217 — classify_http_path ignores method, so GET /v1/ingestions and job-status polls are recorded as raglogs_ingest_request_duration_seconds. README says that histogram is write latency (POST /v1/ingestions*). Status polling will distort ingest p99.

2. src/core/ingestion/service.py:307-365 (same pattern at 486–573 and 650–665) — ingest spans use start_span(...).__enter__() and finally: ingest_cm.__exit__(None, None, None). Failed ingest does not enter start_span’s except, so traces show a successful ingest span. Use with start_span(...): around the existing try/except.

3. src/observability/middleware.py:37-46 — when the current span is invalid (OTEL_SDK_DISABLED=true, or no SDK span), traceparent is built from X-Request-Id after stripping hyphens. A client id like req-from-caller becomes a non-hex trace-id (reqfromcaller000…). W3C traceparent requires 32 hex chars; proxies/collectors will drop it. Generated UUIDs happen to be hex; incoming ids are not. Hash or ignore non-hex ids.

4. src/observability/metrics.py:144-161 — every /metrics scrape calls check_connection() then COUNT on WorkerJob with no connect timeout. A wedged Postgres stalls Prometheus (and a threadpool worker) for the TCP timeout. On failure the gauge is set to 0, which looks like an empty queue. Use a short timeout, cache the last good depth, or leave the gauge stale; don’t publish 0 as “healthy empty”.

Nice-to-have

1. clients/openapi.json:41-44 — /metrics is documented as application/json; the handler returns Prometheus text/plain.
2. tests/unit/test_observability.py:126-141 — captures request_id on http_request only; never asserts scope. /health and /metrics access logs omit scope (no bind_request_scope).
3. LLM “cost” is raglogs_llm_estimated_tokens_total (chars/4), not USD; fine as a proxy, worth saying so in the metric help.
4. Ingest duration is observed only on the success path, so failed runs disappear from raglogs_ingest_duration_seconds.

Verdict

Needs changes (should-fix remain)

[cursor]

Review — PR #49 (G12 self-observability, round 2)

Round-1 should-fix items are addressed. Touched-file ruff is clean. python3 -m pytest tests/unit/ → 740 passed.

Verified

1. classify_http_path takes method; GET /v1/ingestions* is query / ingestions.
2. Ingest paths use with start_span(...); failures mark the span ERROR.
3. Non-hex X-Request-Id is hashed to 32 hex; traceparent is no longer padded garbage.
4. Queue gauge is registered only after a successful scrape; DB failure leaves it omitted/stale, not 0.

Must-fix

(None)

Should-fix

(None)

Nice-to-have

1. When there is no valid SDK span, fallback traceparent still uses parent-id 0000000000000000. W3C forbids an all-zero parent-id; strict proxies may drop the header. Default (SDK on) uses a real span-id.
2. check_connection() still has no connect timeout, so a wedged Postgres can stall /metrics before the 2s statement timeout on COUNT. The false “empty queue” reading is gone.

Verdict

Ready to merge (0 must-fix, 0 should-fix)