Skip to content

feat: Observability and metrics - #848

Merged
lmorchard merged 3 commits into
mainfrom
feat/metrics
Sep 15, 2026
Merged

lmorchard merged 3 commits into
mainfrom
feat/metrics

Conversation

@mokagnomebot

@mokagnomebot mokagnomebot Bot commented Aug 18, 2026

Copy link
Copy Markdown

Closes #10

Prometheus-scrapable counters and latency for the agent loop, derived entirely from EventBus events (llm_end, tool_end, loop_breaker) — no new call sites in the agent loop. Exposed at GET /metrics, with durable sidecars under telemetry/ for after-the-fact analysis. See docs/metrics.md.

Acceptance criteria

id criterion check result
C1 LLM call latency recorded pytest tests/test_metrics.py::test_llm_call_latency_recorded pass
C2 Tool usage metrics recorded pytest tests/test_metrics.py::test_tool_usage_metrics_recorded pass
C3 Metrics or health endpoints structured metrics pytest tests/test_metrics.py::test_metrics_endpoint_or_query pass
C4 model label resolves on the default-model path pytest tests/test_metrics.py -k llm_end_carries_resolved_model pass
C5 Recording path does no I/O and cannot reach the workspace pytest tests/test_metrics.py -k does_no_io pass
C6 Subscriber is config.telemetry.metrics_enabled-gated pytest tests/test_metrics.py -k is_config_gated pass
C7 Label values escaped for exposition pytest tests/test_metrics.py -k escaped pass

Review fixes

Five issues from review, each with a regression test verified to fail without its fix:

  • The model label was empty for nearly every call. It published ctx.active_model, which is "" unless the conversation pinned a named model config — so all default-model traffic collapsed into llm_calls_total{model=""}, which Prometheus cannot distinguish from an absent label. Now publishes the model actually used: explicit override, else pinned config, else default_model.
  • Durable writes blocked the event loop. record_metric opened a fresh SQLite connection and re-ran the DDL per metric, then committed, then appended JSONL — all synchronously, while EventBus.publish awaits subscribers inline on the publishing coroutine. That stalled every concurrent tool call, stream chunk, and WebSocket send for ~3ms per tool call. Initially fixed with a thread offload and a pooled connection — then superseded: see below.
  • The subscriber was wired unconditionally while its four siblings in runner.py are each gated on config.telemetry.*_enabled, leaving no way to switch off the disk writes. Added telemetry.metrics_enabled.
  • Neither sidecar rotated or pruned, and both sat at the workspace root where the Files tab and workspace_recent walks surface them. Initially fixed by moving them under telemetry/ with rotation and pruning — then superseded: see below.
  • Label values were unescaped. A quote, backslash, or newline produced a malformed exposition line, and Prometheus fails the entire scrape on one parse error — so one oddly-named model config would drop every metric. Reachable now that real model names reach the exposition.

Also hoisted a function-level import time in agent.py per CLAUDE.md.

Then: the sidecars came out entirely (a3207e46)

Reviewing the fixes surfaced a better question than "how do we make these writes safe." Neither sidecar had a reader — no module, no make target, no query helper — and Prometheus, the intended consumer, owns retention and querying on its side of the scrape. They were two write-only copies of data the scrape target already stores.

So they're gone, and most of the machinery above went with them: no _persist, no asyncio.to_thread offload, no pooled connection or lock, no rotation call, no retention prune, no index. record_metric is allocation-only, which solves the event-loop stall by construction instead of relocating it to a worker thread. metrics.py went from 264 lines to 139; the commit is net −255.

The subscriber factory no longer takes config. That's load-bearing rather than cosmetic: with no config there's no route to workspace_path, so a sidecar can't reappear by accident. A structural test pins that alongside "this module imports nothing that does I/O."

What survives from the original review: the model-label fix and the label escaping, both of which are about the exposition — now the only surface. metrics_enabled survives as the gate on wiring the subscriber; metrics_path and metrics_db_path are gone.

Trade-off accepted: counters reset on restart. Prometheus handles that for rate()/increase() via counter-reset detection, so rate-based dashboards and alerts are unaffected, but lifetime totals across restarts aren't available. If local history without Prometheus is ever wanted, the answer is a scrape target, not a sidecar here.

Docs

New docs/metrics.md, wired into docs/index.md and cross-linked from observability.md and config.md; three new rows in the config table; metrics.py added to the CLAUDE.md key-files list. docs/data-layout.md was missing telemetry/ from the workspace tree entirely, so the directory was added with its existing contents alongside the new files.

Known gaps, documented not fixed

Recorded in docs/metrics.md rather than left silent:

  • Histograms emit only _sum / _count, no _bucket series, so histogram_quantile() returns empty and the # TYPE ... histogram line overstates what is there.
  • Cancelled LLM calls still publish llm_end with full wall-clock duration, inflating the latency average.
  • The OpenAPI schema declares application/json for this endpoint's text/plain response. Latent until the generated client is imported (Generated OpenAPI TS client is unusable: no emit step, and every route signature is untyped #843).
  • /metrics is unauthenticated, like /health, on a default 0.0.0.0 bind — a deliberate choice to confirm, not an omission.
  • Counters are process-lifetime only, so /metrics is only useful with something scraping it on an interval. Deliberate — see the trade-off above.

Merge gate

Rebased onto main (d78f1095) and force-pushed, so the prior gate's CI reference at 3487ae9d no longer exists. Re-run against the current head.

tier: needs-review
checks: C1-C8 pass
project-gates: ruff clean · pyright 0 errors · tsc --noEmit clean · 3897 passed, 2 skipped
ci: 2/2 pass @ 083443dc
merge-state: CLEAN
verdict: awaiting-review
reason: green, but the previous auto-merge verdict was against a head that no longer exists and the amended scope (five review fixes) has not been reviewed

Note on the first CI run at this head

The two model-label tests initially failed CI with httpx.ConnectError while passing locally. They stubbed agent.call_llm, but _call_llm_with_events takes the call_llm_streaming branch by default (llm.streaming defaults true) and imports it from .llm inside the function, so that seam stayed live — and the default llm.url is a LAN address that is reachable from a dev machine but not from CI. Fixed in 083443dc by stubbing both seams, asserting the stub recorded the call, and parametrizing over streaming on/off. Filed as #851 so the next test to make this mistake fails locally instead of only in CI.

@mokagnomebot mokagnomebot Bot added the agent-session:gate PR has a merge gate block and is ready for grading label Aug 18, 2026

@lmorchard lmorchard left a comment

Copy link
Copy Markdown
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Do these metrics need to use a SQLite table? Or could we just maintain these metrics in a JSONL file?

lmorchard added a commit that referenced this pull request Sep 15, 2026
Four issues from the review of #848, each with a regression test:

- The `model` label was `ctx.active_model`, which is "" unless the
  conversation pinned a named model config — so every default-model call
  landed in `llm_calls_total{model=""}`, which Prometheus cannot tell
  apart from an absent label. Publish the model actually used:
  explicit override, else pinned config, else `default_model`.

- `record_metric` opened a fresh SQLite connection and re-ran the DDL on
  every metric, then committed, then appended JSONL — all synchronously.
  `EventBus.publish` awaits subscribers inline on the publishing
  coroutine, so that stalled the agent loop (and every concurrent tool
  call, stream chunk, and WebSocket send) for ~3ms per tool call. Split
  the in-memory update (cheap, stays on the loop) from `_persist`
  (offloaded via `asyncio.to_thread`), and reuse one connection per path.

- The subscriber was wired unconditionally while its four siblings are
  each gated on `config.telemetry.*_enabled`, leaving no way to switch
  off the disk writes. Add `telemetry.metrics_enabled` and gate it.

- Neither sidecar rotated or pruned, and both sat at the workspace root
  where the Files tab and `workspace_recent` walks surface them. Move
  them under `telemetry/` via config, rotate the JSONL through the shared
  `rotate_if_needed`, prune the table on connection open, and index it.

Also hoists the function-level `import time` in agent.py to module level
per CLAUDE.md, since there is no cycle to break there.
Five issues from review, each with a regression test verified to fail
without its fix:

- The `model` label was `ctx.active_model`, which is "" unless the
  conversation pinned a named model config — so every default-model call
  landed in `llm_calls_total{model=""}`, which Prometheus cannot
  distinguish from an absent label. Publish the model actually used:
  explicit override, else pinned config, else `default_model`.

- Label values were not escaped. A quote, backslash, or newline produced
  a malformed exposition line, and Prometheus fails the *entire* scrape
  on one parse error — so a single oddly-named model config would drop
  every metric, not just its own.

- The subscriber was wired unconditionally while its four siblings are
  each gated on `config.telemetry.*_enabled`. Added
  `telemetry.metrics_enabled`.

- `record_metric` opened a fresh SQLite connection, re-ran the DDL,
  committed, and appended JSONL on every metric — all synchronously,
  while `EventBus.publish` awaits subscribers inline on the publishing
  coroutine. That stalled the agent loop, and with it every concurrent
  tool call, stream chunk, and WebSocket send.

- Neither sidecar rotated or pruned, and both sat at the workspace root
  where the Files tab and `workspace_recent` walks surface them.

The last two are fixed by removing their cause rather than managing it.
Neither sidecar had a reader — no module, no `make` target, no query
helper — and Prometheus, the intended consumer, owns retention and
querying on its side of the scrape. They were two write-only copies of
data the scrape target already stores, so they are gone, along with the
thread offload, the pooled connection and lock, the rotation call, the
retention prune, and the index. `record_metric` is now allocation-only,
which removes the event-loop stall by construction instead of relocating
it to a worker thread. `metrics.py` is 139 lines, down from 264.

`make_metrics_subscriber()` no longer takes `config`. That is
load-bearing: with no config there is no route to `workspace_path`, so a
sidecar cannot return by accident. A structural test pins it alongside
"this module imports nothing that does I/O".

Trade-off accepted: counters reset on restart. Prometheus handles that
for `rate()`/`increase()` via counter-reset detection, so rate-based
dashboards are unaffected, but lifetime totals across restarts are not
available. If local history without Prometheus is ever wanted, the answer
is a scrape target, not a sidecar here.

Docs: new docs/metrics.md wired into docs/index.md and cross-linked from
observability.md and config.md; `metrics.py` added to the CLAUDE.md
key-files list. docs/data-layout.md was missing `telemetry/` from the
workspace tree entirely, so the directory was added with its existing
contents. Known gaps recorded rather than left silent: histograms declare
a type whose `_bucket` series they do not emit, cancelled LLM calls count
as completed, and the OpenAPI schema declares the wrong media type (#843).

Also hoists a function-level `import time` in agent.py per CLAUDE.md, and
stubs both LLM seams in the model-label tests — `_call_llm_with_events`
branches on `resolve_streaming` and the streaming branch imports
`call_llm_streaming` from `.llm` inside the function, so patching one
seam left the other live against a LAN default URL. Filed as #851.
@lmorchard
lmorchard merged commit 9906ee5 into main Sep 15, 2026
2 checks passed
@lmorchard
lmorchard deleted the feat/metrics branch September 15, 2026 21:20
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

agent-session:gate PR has a merge gate block and is ready for grading

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Observability and metrics

2 participants