feat(observability): RPC + workflow + DB-pool metrics for the agent JSON-RPC endpoint - #379
feat(observability): RPC + workflow + DB-pool metrics for the agent JSON-RPC endpoint#379stephen-wang24 wants to merge 9 commits into
Conversation
- agentex.rpc.request.duration / requests / errors with OTel RPC semconv attributes (rpc.system.name, rpc.method, rpc.response.status_code, error.type) plus streaming; never-raise emission - OTel-only: these series are new, so there is no StatsD dual-emit — nothing on the Datadog side consumes them yet - Streaming responses are timed dispatch-to-final-byte with a single terminal emit in the stream's finally block - Explicit bucket boundaries: seconds-scale histograms need the OTel HTTP semconv boundaries extended upward, or every sub-5-second observation lands in a single bucket - One structured 'Agent RPC completed' log line per request carrying the terminal fields (status, error.type, duration_ms) - High-cardinality identifiers (task id, agent id, request id) deliberately excluded from metric attributes Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
…-point RPCs task/create is the workflow-level entry point for an agent invocation, so record_rpc_request now additionally records a gen_ai.workflow.duration histogram labeled with the GenAI operation name (invoke_workflow), plus error.type on failure. Workflow-level duration becomes directly queryable instead of being inferable only from RPC duration. Labels stay a bounded set; no per-request identifiers. The GenAI semconv pairs gen_ai.workflow.duration with invoke_workflow; invoke_agent stays reserved for the agent loop's own gen_ai.invoke_agent.duration, so queries on either operation name never mix gateway workflow duration with in-pod agent invocation duration. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Add the three high-signal OTel DB connection-pool metrics that the existing
checkout/checkin listeners can't source: by the time the checkout event fires
the wait is already over, SQLAlchemy exposes no "started waiting" event or
waiter count, and a pool checkout timeout raises before any connection is
handed out.
Source them from an InstrumentedAsyncAdaptedQueuePool that wraps
Pool.connect() -- the single, non-recursive acquisition entry point, which runs
inside the acquiring greenlet so wall-clock timing captures the real wait,
including time blocked on a saturated pool. Wrapping _do_get() instead would
double-count, because QueuePool._do_get recurses on itself on the overflow
retry path.
* db.client.connection.wait_time (Histogram, s) -- explicit
second-scale buckets so quantiles stay usable, unlike the default
ms-magnitude boundaries against a seconds unit
* db.client.connection.pending_requests (UpDownCounter) -- +1/-1 around the
acquire; ~0 normally, rises to the true waiter count under saturation
* db.client.connection.timeouts (Counter) -- pool acquisition timeouts
Instruments are attached to the pool post-construction (the pool is built
inside create_async_engine before the collector has meters); connect() is a
plain passthrough until then and whenever OTel is unconfigured. recreate()
carries the instruments forward so a dispose doesn't silently drop the series.
OTel-only, no StatsD dual-emit: these are new series with no Datadog consumer.
Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
Rename the JSON-RPC metric attributes to the names the OTel RPC semantic conventions actually define: * rpc.system.name -> rpc.system * rpc.response.status_code -> rpc.jsonrpc.error_code rpc.jsonrpc.error_code is now set only when the call failed (per the semconv's conditionally-required rule) and carries the integer error code (e.g. -32603) rather than a string status; success omits it entirely. record_rpc_request takes error_code: int | None in place of status_code: str -- None means success -- and the error counter fires on error_code is not None. The structured completion log keeps a friendly status: ok|<code> field. No metric-name changes and no new series; the custom agentex.rpc.* names and the dedicated agentex.rpc.errors counter are unchanged. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
…h cluster names The local dev collector set `prometheus.namespace: agentex`, which prepends `agentex_` to every exported series. Metrics already named `agentex.*` came out double-prefixed (`agentex_agentex_rpc_requests_total`), so PromQL tested against the local collector didn't match what Mimir sees. The cluster's otel-operator -> daemonset pipeline adds no such prefix — series there are exactly their instrument names (`agentex_rpc_requests_total`, `db_client_connection_wait_time_seconds`, `gen_ai_workflow_duration_seconds`). Removing the namespace makes local names identical to cluster/Mimir names, so queries developed locally port over unchanged. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
| # else: | ||
| # raise ValueError(f"Unsupported method: {request.method}") | ||
| # logger.info(f"AgentRPCResponse Result: {result}") | ||
| record_rpc_request( |
There was a problem hiding this comment.
record_rpc_request fires before AgentRPCResponse.model_validate on the success path. If that validation raises, the except ValidationError branch records the same request a second time as a -32602 error, so agentex.rpc.requests and the duration histogram count it twice. Suggest validating first, then recording:
response = AgentRPCResponse.model_validate(
{"id": request.id, "result": serialized_result, "error": None}
)
record_rpc_request(
method=request.method.value,
streaming=False,
duration_s=time.perf_counter() - start,
)
return responseThere was a problem hiding this comment.
good point, will record it after the validation to avoid double metricing
There was a problem hiding this comment.
Fixed in 15ba465. Recording now goes through a rpc_request_timing context manager that records exactly once when the handler scope exits, and model_validate runs inside that scope, if it raises, the except ValidationError branch classifies the call as -32602 and that's the single record. Double counting is structurally impossible now.
| ) | ||
| yield error_response.model_dump_json().encode() + b"\n" | ||
| finally: | ||
| record_rpc_request( |
There was a problem hiding this comment.
nit: a client disconnect mid-stream raises GeneratorExit (or CancelledError) at the yield, which skips the except Exception branch, so this finally records the request as a success with a truncated duration. That deflates streaming duration percentiles and inflates the success rate. Suggest tracking error_code and error_type separately so disconnects carry error.type without counting as JSON-RPC errors (record_rpc_request already supports that combination, since the error counter is driven only by error_code):
error_type: str | None = None
error_code: int | None = None
...
except (GeneratorExit, asyncio.CancelledError) as e:
# Client went away mid-stream: tag it, but not a JSON-RPC error.
error_type = type(e).__name__
raise
except Exception as e:
error_type = type(e).__name__
error_code = -32603
...
finally:
record_rpc_request(
...,
error_code=error_code,
error_type=error_type,
)That also lets dashboards exclude disconnects from percentiles via error.type, and drops the None if error_type is None else -32603 derivation.
| # Connection-acquisition metrics (OTel DB semconv). Sourced from the | ||
| # InstrumentedAsyncAdaptedQueuePool.connect() seam rather than pool | ||
| # events, which can't see the wait, the current waiters, or a timeout. | ||
| self._connection_wait_time: Histogram = meter.create_histogram( |
There was a problem hiding this comment.
I guess we should measure how long a connection is held.. So, here we are measuring the wait to acquire a connection but not how long it's been held. Pool exhaustion is a function of both i.e how long requests queue and how long connections stay checked out once acquired
There was a problem hiding this comment.
Yes, hold time is covered above in db.client.connection.use_time
| try: | ||
| connection = super().connect() | ||
| except SQLAlchemyTimeoutError: | ||
| instruments.timeouts.add(1, attributes) |
There was a problem hiding this comment.
So we're only capturing timeouts? Timeout is good but connect can fail for numerous reasons right?. Say, what if Postgres is rejecting a connection due to max connections already reached on the DB? Or there's a network drop? It's neither a timeout nor a successful wait, so it just goes dark.. worth adding a catch-all failure path for that.
There was a problem hiding this comment.
Good point, i was adding for metrics in semconv and failure is not one of it, added in 15ba465 for emitting generic failures
| wait is already over, SQLAlchemy exposes no "started waiting" event, and a | ||
| pool timeout raises before any connection is handed out. | ||
|
|
||
| ``Pool.connect()`` is the single, non-recursive entry point for obtaining a |
| request_headers: dict[str, str] | None = None, | ||
| ) -> AgentRPCResponse: | ||
| """Handle synchronous JSON-RPC requests.""" | ||
| start = time.perf_counter() |
There was a problem hiding this comment.
Could we pull this into a @contextmanager that handles start/end timing and records the metric (including error classification) in one place, rather than each handler managing start = time.perf_counter() and calling record_rpc_request at every exit point? That would let us reuse it across the library instead of repeating the same start/duration/record pattern in every function that needs rpc timing
There was a problem hiding this comment.
Sounds good. Done in 15ba465 to use a context manager
- Record each RPC call exactly once via a rpc_request_timing context manager; a response-validation failure no longer records the same request twice (once as success, once as -32602) - Classify mid-stream client disconnects (GeneratorExit/CancelledError) with error.type but no JSON-RPC error code, so truncated streams neither count as errors nor read as clean successes - Count non-timeout connection-acquisition failures in a catch-all db.client.connection.failures_total counter tagged with error.type Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Summary
Brings the agent JSON-RPC endpoint (
POST /agents/{id}/rpc—task/create/message/send/event/send) up to the metrics observability contract, and adds high-signal Postgres connection-pool saturation metrics. Everything here is OTel-only (no StatsD dual-emit — these are new series with no existing consumer), and a cheap no-op when no OTLP endpoint is configured.RPC RED metrics (
agentex.rpc.*)agentex.rpc.request.duration(timed dispatch → final byte, so streaming responses are covered end-to-end),agentex.rpc.requests,agentex.rpc.errors.rpc.system,rpc.method,rpc.jsonrpc.error_code,error.type,streaming. No high-cardinality identifiers (no task/agent/request ids). JSON-RPC failures return HTTP 200, so the error code rides onrpc.jsonrpc.error_code(set only on failure), not an HTTP status.Workflow-level GenAI metric
gen_ai.workflow.durationfortask/create, labeledgen_ai.operation.name=invoke_workflow, so workflow-level duration is directly queryable instead of only inferable from RPC duration.invoke_agentstays reserved for the agent loop's own duration, so the two operation names never mix gateway and in-pod durations.DB connection-pool metrics (OTel DB semconv)
db.client.connection.wait_time,db.client.connection.pending_requests,db.client.connection.timeouts— the pre-outage early-warning signals for pool exhaustion.InstrumentedAsyncAdaptedQueuePoolthat wrapsPool.connect()(the single, non-recursive acquisition entry point, run inside the acquiring greenlet). The existing checkout/checkin listeners can't produce these: by the timecheckoutfires the wait is over, there's no waiter count, and a pool timeout raises before any connection is handed out.wait_timeuses explicit second-scale histogram buckets so quantiles stay usable (the SDK default boundaries assume a millisecond unit).Testing
tests/unit/utils/test_rpc_metrics.pyandtest_db_metrics.py: unconfigured no-op, never-raise on backend faults, metric name/attribute assertions, and the pool success / timeout / non-timeout-error paths. All green;ruffclean.Notes / follow-ups
http_server_request_duration_seconds) lands on a separate branch.🤖 Generated with Claude Code
Greptile Summary
This PR adds OTel-only RED metrics for the agent JSON-RPC endpoint (
agentex.rpc.*), a GenAI workflow-duration histogram fortask/create, and Postgres connection-pool acquisition metrics (db.client.connection.wait_time/pending_requests/timeouts/failures) sourced from a newInstrumentedAsyncAdaptedQueuePoolsubclass. It also removes thenamespace: agentexfrom the local OTel collector's Prometheus exporter to fix a double-prefix bug that would have appeared for newagentex.*-prefixed instrument names.@contextmanager(rpc_request_timing) wraps both sync and streaming handlers; aRpcCallOutcomedataclass lets handlers classify JSON-RPC error codes, withBaseExceptioncatching client disconnects (e.g.,GeneratorExit) separately from structured RPC errors. Never-raise contract is enforced throughout.InstrumentedAsyncAdaptedQueuePool.connect()is the correct interception seam (checkout/checkin events can\u2019t see the wait or a timeout), instruments are attached post-construction and carried acrossrecreate(), and thewait_timehistogram uses explicit second-scale buckets to keep quantiles usable.namespace: agentexaligns local PromQL with the production Mimir pipeline but renames existingagentex_db_*local series todb_*; teams with local Grafana dashboards querying the old prefixed names will need to update their queries.Confidence Score: 5/5
Safe to merge; all changes are additive instrumentation with a never-raise emission contract and no mutations to the core RPC execution path.
The RPC and DB pool metric additions are purely observational. The rpc_request_timing contextmanager correctly handles BaseException including GeneratorExit, the pool override degrades to a passthrough when OTel is unconfigured, and recreate() carries instrumentation forward. Unit tests cover the no-op path, never-raise contract, double-count regression, and the streaming GeneratorExit scenario.
Files Needing Attention: No files require special attention. The otel-collector-config.yaml namespace removal warrants a local dashboard audit if Prometheus queries exist against the old agentex_db_*-prefixed series.
Important Files Changed
Sequence Diagram
sequenceDiagram participant Client participant agents_py as agents.py participant rpc_timing as rpc_request_timing participant use_case as agents_acp_use_case participant otel as OTel SDK Client->>agents_py: "POST /agents/{id}/rpc" agents_py->>rpc_timing: __enter__ (start timer) rpc_timing-->>agents_py: RpcCallOutcome alt Sync request agents_py->>use_case: handle_rpc_request() use_case-->>agents_py: result_entity agents_py->>rpc_timing: __exit__ (normal) rpc_timing->>otel: record duration/requests agents_py-->>Client: AgentRPCResponse (200) else Streaming request agents_py->>use_case: handle_rpc_request() use_case-->>agents_py: AsyncIterator loop Each chunk agents_py-->>Client: NDJSON chunk (yield) end alt Stream error agents_py->>rpc_timing: rpc_call.fail(-32603, e) agents_py-->>Client: error frame (yield) end agents_py->>rpc_timing: __exit__ (GeneratorExit or normal) rpc_timing->>otel: record duration/requests/errors end Note over agents_py,otel: task/create also emits gen_ai.workflow.durationReviews (6): Last reviewed commit: "Merge branch 'main' into stephen-wang/rp..." | Re-trigger Greptile