Fix/per operation timing instrumentation

[jdlake]

HUMAN:

Wrote per-operation timing for the agent-server lifecycle ops in issue #4589 — conversation_create/delete/close, event_service_load, conversation_info_compose, and conversation_evict (bucketed evicted_count) — via the new timed_operation stuck-watchdog helper and the allowlisted OperationTimingProperties schema, with focused tests per operation. When a call site passes no budget_ms, default to DEFAULT_STUCK_BUDGET_MS = 20_000, so really only alerts on a genuinely wedged/locked operation (currently all call sites use this).

From the same issue, deliberately not instrumented yet:

• event_search / bash_event_search — sync executor scans; needs a sync-timer variant plus a decision on the count/fan-out magnitude (raw counts are re-identifying).
• llm_call / switch_llm config serialization — the SDK LLM has no telemetry tap today; needs a cross-package sink hook and a contention/lock-wait timer (wire time =/= lock-wait time).
• Lease renewal / autosave / pub/sub / condensation — background loops and cross-module fan-out; needs a defined per-iteration operation boundary and the same cross-package hook.

---

Want it collapsed to a single block (e.g. for a PR description or commit body) or kept as bullets?

---

AGENT:

Why

Issue #4589 asks for per-operation wall-clock timing instrumentation on the
agent-server operations that have historically been slow or deadlocked, so
latency percentiles and stuck signals stop being guesswork. The first slice
(create/delete/close lifecycle ops) landed in commit 44ff83ec; this PR
completes the remaining agent-server-local slice: event_service_load,
conversation_info_compose, and conversation_evict.

Summary

• Timed event_service_load from before lifecycle-lock acquisition through
  hydration, so a lock-wedged load surfaces as stuck with no completion,
  while a slow hydration surfaces as a long raw duration.
• Timed both _compose_conversation_info* call sites in _conversation_info
  (live in-memory path incl. get_state(), and the persisted to_thread
  path), covering the off-loop compose wedge that previously stalled sidebar
  listing.
• Timed one pass of _evict_idle_conversations (only when ≥1 conversation is
  evicted, so empty passes don't deflate the percentile) and attached a
  bucketed evicted_count magnitude (COUNT_BOUNDS), never a raw count —
  raw counts joined with a timestamp are the re-identification vector this
  telemetry contract exists to avoid.
• Extended OperationTimingProperties with the optional bucketed
  evicted_count field and updated the EXPECTED_PROPERTY_NAMES allowlist
  plus schema tests. The timed_operation helper now supports attaching a
  bucketed count to the emitted result.

Issue Number

Fixes #4589

How to Test

Automated (all green on the final commit f218cee5):

uv run pytest tests/agent_server/test_conversation_service.py::TestOperationTimingInstrumentation \
  tests/agent_server/telemetry/ -q
# 281 passed, 50 warnings in 76.25s

What the suite covers

TestOperationTimingInstrumentation (7 tests): each of conversation_create / conversation_delete / conversation_close / event_service_load / conversation_info_compose emits a timing completion with a plausible raw duration_ms, plus "stuck" variants that hold a conversation lock beyond the budget and assert a stuck event is emitted without a completion event (deadlock shape). A conversation_evict pass emits a completion with a bucketed evicted_count.

Telemetry suite (tests/agent_server/telemetry/): the timing helper (completion-on-exit, single-stuck-watchdog, bucketed-count exposure), the OperationTimingProperties schema, and the deny/allow EXPECTED_PROPERTY_NAMES allowlist tests — including that no raw count or conversation_ref leaks onto the event.

Manual smoke (what I verified end-to-end)

1. Server boots with telemetry enabled:

   OH_TELEMETRY_CONSENT=enabled uv run openhands-agent-server

   No startup crash; timing module imports cleanly with consent resolution lazy.

2. Create a conversation via POST /api/conversations, then GET /api/conversations/{id} (drives conversation_info_compose) and resume it (POST /api/conversations/{id} resume → event_service_load). With an HTTP exporter configured, observe agent_server.operation_timing events with stuck=false and plausible duration_ms for all three operations.

3. Eviction only emits when it acts: idle a conversation past TTL and observe one conversation_evict event with evicted_count in COUNT_BOUNDS vocabulary (e.g. 1), never the raw count.

I could not run a full live load/hot-loop session in this sandbox, so the stuck-watchdog path is exercised via the unit "stuck" variants rather than a real deadlock reproduction.

---

Video/Screenshots

N/A — telemetry-only change; verified via the test log below and (optionally) an HTTP-exporter capture. Representative test output (final commit):

tests/agent_server/telemetry/test_telemetry_timing.py ............. [..%]
...
================= 281 passed, 50 warnings in 76.25s (0:01:16) ==================

---

Design Doc

.pr/design.md

---

Type

• Bug fix
• Feature
• Refactor
• Breaking change
• Docs / chore

---

Notes

• The re-identification rationale for allowlisting raw durations but bucketing all counts is documented in OperationTimingProperties in telemetry/models.py and in .pr/design.md.
• .pr/design.md is temporary PR context: the repo's pr-artifacts.yml workflow auto-removes it on approval for same-repo PRs, but fork PRs need manual removal before merge — I can drop it again if you prefer it gone.
• Remaining out-of-scope slices from Add per-operation timing instrumentation for historically slow/deadlocked operations #4589 (event search, LLM-call contention, lease/autosave/pubsub/condensation) deliberately need either a sync-timer variant, a contention timer, or cross-package plumbing; they are tracked as follow-ups, not in this PR.

[github-actions]

📁 PR Artifacts Notice

This PR contains a .pr/ directory with temporary PR-specific documents. Because this is a fork PR, the directory will be automatically removed from main immediately after merge.