Record pool and turn metrics through the telemetry adapter - #686
Record pool and turn metrics through the telemetry adapter#686samuelcolvin wants to merge 6 commits into
Conversation
![veria-ai[bot]](https://avatars.githubusercontent.com/in/1723776?s=60&v=4){kind=small}
PR overviewAll previously flagged issues have been addressed. No open security concerns remain on this pull request. Security reviewNo open security issues remain on this pull request. Fixed/addressed: 1 · PR risk: 0/10 |
![macroscopeapp[bot]](https://avatars.githubusercontent.com/in/900172?s=60&v=4){kind=small}
| for _ in 0..died_idle { | ||
| self.count_termination("died_idle"); | ||
| } | ||
| self.record_workers(idle, busy); |
There was a problem hiding this comment.
🟡 Medium src/pool.rs:238
record_workers(idle, busy) in acquire_worker_inner snapshots the state under the lock, then publishes after releasing it. A concurrent acquire/release can publish a newer snapshot in between, after which this call publishes the stale values last — leaving the worker gauge wrong until the next state transition. For example, a release snapshots (1, 0), a concurrent checkout consumes that worker and records (0, 1), then the release records (1, 0). Recording must stay outside the mutex, but needs a version/seq-lock guard or a re-snapshot-under-lock strategy so a stale snapshot cannot overwrite a newer one.
🚀 Reply "fix it for me" or copy this AI Prompt for your agent:
In file @crates/monty-pool/src/pool.rs around line 238:
`record_workers(idle, busy)` in `acquire_worker_inner` snapshots the state under the lock, then publishes *after* releasing it. A concurrent acquire/release can publish a newer snapshot in between, after which this call publishes the stale values last — leaving the worker gauge wrong until the next state transition. For example, a release snapshots `(1, 0)`, a concurrent checkout consumes that worker and records `(0, 1)`, then the release records `(1, 0)`. Recording must stay outside the mutex, but needs a version/seq-lock guard or a re-snapshot-under-lock strategy so a stale snapshot cannot overwrite a newer one.
| ); | ||
| self.end_turn("ok"); | ||
| } | ||
| Some(pb::child_event::Kind::Ok(_)) => self.end_turn("ok"), |
There was a problem hiding this comment.
🟡 Medium src/metrics.rs:493
When a Load request adopts a dumped session whose cumulative execution clock is nonzero, the next feed's monty.run.execution_time is inflated by the pre-snapshot execution time. begin_turn resets reported_micros to 0 for Load, but the Ok event that answers a Load only calls end_turn — it never rebases reported_micros to the loaded session's total_execution_micros. So when the first feed after the load completes, end_run computes the delta as total - 0, recording the entire cumulative clock as that one feed's execution time. Rebase reported_micros from the total_execution_micros on the Load response before the next feed begins.
🚀 Reply "fix it for me" or copy this AI Prompt for your agent:
In file @crates/monty-pool/src/metrics.rs around line 493:
When a `Load` request adopts a dumped session whose cumulative execution clock is nonzero, the next feed's `monty.run.execution_time` is inflated by the pre-snapshot execution time. `begin_turn` resets `reported_micros` to `0` for `Load`, but the `Ok` event that answers a `Load` only calls `end_turn` — it never rebases `reported_micros` to the loaded session's `total_execution_micros`. So when the first feed after the load completes, `end_run` computes the delta as `total - 0`, recording the entire cumulative clock as that one feed's execution time. Rebase `reported_micros` from the `total_execution_micros` on the `Load` response before the next feed begins.
ApprovabilityVerdict: Approved c5f9783 This PR adds new metrics recording capability through the telemetry adapter - an additive feature that doesn't modify unsafe code, sandbox boundaries, wire protocol parsing, snapshot formats, or break public APIs. Per repository guidelines, correctness concerns are handled separately by the Correctness check. You can customize Macroscope's approvability policy. Learn more. |
![cubic-dev-ai[bot]](https://avatars.githubusercontent.com/in/1082092?s=60&v=4){kind=small}
There was a problem hiding this comment.
3 issues found across 20 files
Prompt for AI agents (unresolved issues)
Check if these issues are valid — if so, understand the root cause of each and fix them. If appropriate, use sub-agents to investigate and fix each issue separately.
<file name="crates/monty-pool/src/worker.rs">
<violation number="1" location="crates/monty-pool/src/worker.rs:309">
P2: Restoring a snapshot taken during a suspension records `monty.turn.duration` for `load` only when the later resumed feed ends, so the load metric includes arbitrary host/sandbox time and gets the wrong outcome. Close the pending `load` turn when its re-announced suspension is received, before opening that suspension's host-call metric.</violation>
</file>
<file name="crates/monty-pool/src/metrics.rs">
<violation number="1" location="crates/monty-pool/src/metrics.rs:394">
P1: Restored sessions report all pre-dump execution again in the next `monty.run.execution_time` sample because this reset is never rebased from the `Load` reply. Capture `event.total_execution_micros` when handling that reply before a later feed ends.</violation>
</file>
<file name="crates/monty-pool/src/pool.rs">
<violation number="1" location="crates/monty-pool/src/pool.rs:238">
P2: Concurrent checkouts/releases can leave `monty.pool.workers` reporting stale or internally inconsistent idle/busy values because snapshots are recorded after releasing `state` without preserving mutation order. Serialize each state-change-and-gauge-publication sequence outside the pool mutex, or otherwise publish only the newest snapshot.</violation>
</file>
Reply with feedback, questions, or to request a fix.
Re-trigger cubic
| self.feed = None; | ||
| self.pending = None; | ||
| self.turn = Some(("configure", now)); | ||
| self.reported_micros = 0; |
There was a problem hiding this comment.
P1: Restored sessions report all pre-dump execution again in the next monty.run.execution_time sample because this reset is never rebased from the Load reply. Capture event.total_execution_micros when handling that reply before a later feed ends.
Prompt for AI agents
Check if this issue is valid — if so, understand the root cause and fix it. At crates/monty-pool/src/metrics.rs, line 394:
<comment>Restored sessions report all pre-dump execution again in the next `monty.run.execution_time` sample because this reset is never rebased from the `Load` reply. Capture `event.total_execution_micros` when handling that reply before a later feed ends.</comment>
<file context>
@@ -0,0 +1,1193 @@
+ self.feed = None;
+ self.pending = None;
+ self.turn = Some(("configure", now));
+ self.reported_micros = 0;
+ }
+ Some(pb::parent_request::Kind::Feed(_)) => {
</file context>
| #[cfg(feature = "telemetry-adapter")] | ||
| if let Some(metrics) = &mut self.metrics { | ||
| metrics.frame("received", len); | ||
| metrics.event(&event); |
There was a problem hiding this comment.
P2: Restoring a snapshot taken during a suspension records monty.turn.duration for load only when the later resumed feed ends, so the load metric includes arbitrary host/sandbox time and gets the wrong outcome. Close the pending load turn when its re-announced suspension is received, before opening that suspension's host-call metric.
Prompt for AI agents
Check if this issue is valid — if so, understand the root cause and fix it. At crates/monty-pool/src/worker.rs, line 309:
<comment>Restoring a snapshot taken during a suspension records `monty.turn.duration` for `load` only when the later resumed feed ends, so the load metric includes arbitrary host/sandbox time and gets the wrong outcome. Close the pending `load` turn when its re-announced suspension is received, before opening that suspension's host-call metric.</comment>
<file context>
@@ -262,6 +303,13 @@ impl Worker {
+ #[cfg(feature = "telemetry-adapter")]
+ if let Some(metrics) = &mut self.metrics {
+ metrics.frame("received", len);
+ metrics.event(&event);
+ }
+ #[cfg(not(feature = "telemetry-adapter"))]
</file context>
| for _ in 0..died_idle { | ||
| self.count_termination("died_idle"); | ||
| } | ||
| self.record_workers(idle, busy); |
There was a problem hiding this comment.
P2: Concurrent checkouts/releases can leave monty.pool.workers reporting stale or internally inconsistent idle/busy values because snapshots are recorded after releasing state without preserving mutation order. Serialize each state-change-and-gauge-publication sequence outside the pool mutex, or otherwise publish only the newest snapshot.
Prompt for AI agents
Check if this issue is valid — if so, understand the root cause and fix it. At crates/monty-pool/src/pool.rs, line 238:
<comment>Concurrent checkouts/releases can leave `monty.pool.workers` reporting stale or internally inconsistent idle/busy values because snapshots are recorded after releasing `state` without preserving mutation order. Serialize each state-change-and-gauge-publication sequence outside the pool mutex, or otherwise publish only the newest snapshot.</comment>
<file context>
@@ -179,33 +209,49 @@ impl PoolInner {
+ for _ in 0..died_idle {
+ self.count_termination("died_idle");
+ }
+ self.record_workers(idle, busy);
+ if let Some(worker) = reused {
+ *outcome = if waited { "waited" } else { "idle" };
</file context>
8640519 to
3b78ff8
Compare
Dismissing prior approval to re-evaluate 3b78ff8
| config.request_timeout = options.request_timeout_ms.map(duration_from_ms).transpose()?; | ||
| config.duration_limit_grace = options.duration_limit_grace_ms.map(duration_from_ms).transpose()?; | ||
| config.max_checkouts_per_worker = options.max_checkouts_per_worker; | ||
| config.metrics = configured_adapter().map(TelemetryAdapterHandle::metrics); |
There was a problem hiding this comment.
🟡 Medium src/pool.rs:201
NativePool::new snapshots configured_adapter() into PoolConfig at construction time. If the telemetry adapter is installed after the NativePool is created, the pool permanently retains metrics = None and silently drops all pool and turn measurements — even for checkouts that happen later. Session tracing avoids this by looking up configured_adapter() at NativeSession::enter time, so the initialization order of telemetry versus pool creation determines whether metrics work. Consider deferring the metrics lookup to pool start or checkout time, matching how tracing resolves the adapter, or document that the adapter must be installed before NativePool construction.
🚀 Reply "fix it for me" or copy this AI Prompt for your agent:
In file @crates/monty-js/src/pool.rs around line 201:
`NativePool::new` snapshots `configured_adapter()` into `PoolConfig` at construction time. If the telemetry adapter is installed after the `NativePool` is created, the pool permanently retains `metrics = None` and silently drops all pool and turn measurements — even for checkouts that happen later. Session tracing avoids this by looking up `configured_adapter()` at `NativeSession::enter` time, so the initialization order of telemetry versus pool creation determines whether metrics work. Consider deferring the `metrics` lookup to pool start or checkout time, matching how tracing resolves the adapter, or document that the adapter must be installed before `NativePool` construction.
There was a problem hiding this comment.
🟡 Medium src/metrics.rs:478
The Error event handler at line 478 only treats dump as a housekeeping turn, so an Error replying to configure, load, reset, or install_dependencies falls into end_run instead of end_turn. This emits monty.run.execution_time and monty.run.duration_budget_used for a housekeeping failure, and may also consume an in-flight feed (via self.feed.take() in end_run), corrupting run metrics. The check should match all housekeeping turn labels, not just dump.
| if matches!(self.turn, Some(("dump", _))) { | |
| if matches!(self.turn, Some(("dump" | "load" | "reset" | "install_dependencies" | "configure", _))) { |
🚀 Reply "fix it for me" or copy this AI Prompt for your agent:
In file @crates/monty-pool/src/metrics.rs around line 478:
The `Error` event handler at line 478 only treats `dump` as a housekeeping turn, so an `Error` replying to `configure`, `load`, `reset`, or `install_dependencies` falls into `end_run` instead of `end_turn`. This emits `monty.run.execution_time` and `monty.run.duration_budget_used` for a housekeeping failure, and may also consume an in-flight `feed` (via `self.feed.take()` in `end_run`), corrupting run metrics. The check should match all housekeeping turn labels, not just `dump`.
Merging this PR will not alter performance
Comparing 
Footnotes
|
Codecov Results 📊❌ Patch coverage is 72.89%. Project has 10006 uncovered lines. Files with missing lines (5)
Coverage diff@@ Coverage Diff @@
## main #PR +/-##
==========================================
- Coverage 83.38% 83.24% -0.14%
==========================================
Files 242 247 +5
Lines 56961 59709 +2748
Branches 120038 125340 +5302
==========================================
+ Hits 47496 49703 +2207
- Misses 9465 10006 +541
- Partials 3297 3355 +58Generated by Codecov Action |
Codecov Report❌ Patch coverage is 📢 Thoughts on this report? Let us know! |
3b78ff8 to
446c570
Compare
Dismissing prior approval to re-evaluate 446c570
Dismissing prior approval to re-evaluate fd2bccc
There was a problem hiding this comment.
1 issue found across 25 files
Prompt for AI agents (unresolved issues)
Check if these issues are valid — if so, understand the root cause of each and fix them. If appropriate, use sub-agents to investigate and fix each issue separately.
<file name="crates/monty-pool/src/checkout.rs">
<violation number="1" location="crates/monty-pool/src/checkout.rs:1322">
P2: A checkout whose worker crashes mid-turn is reported two inconsistent ways: the worker termination shows reason `crash`, but the session lifetime (`monty.pool.session.duration`) is recorded as `abandoned` because `Drop::drop` fires `record_finish("abandoned")` whenever `finish` was never called. That collapses "the worker died" and "the caller chose to drop a live session" into one outcome, which weakens the session-outcome signal this PR is adding. Consider tracking a `finished`/`terminated` flag on the Checkout so the drop path records `abandoned` only when the worker was healthy, and records the session as `error`/`crash` when a termination was already counted.</violation>
</file>
Reply with feedback, questions, or to request a fix.
Re-trigger cubic
| self.pool.release_capacity(); | ||
| } | ||
| #[cfg(feature = "telemetry")] | ||
| self.record_finish("abandoned"); |
There was a problem hiding this comment.
P2: A checkout whose worker crashes mid-turn is reported two inconsistent ways: the worker termination shows reason crash, but the session lifetime (monty.pool.session.duration) is recorded as abandoned because Drop::drop fires record_finish("abandoned") whenever finish was never called. That collapses "the worker died" and "the caller chose to drop a live session" into one outcome, which weakens the session-outcome signal this PR is adding. Consider tracking a finished/terminated flag on the Checkout so the drop path records abandoned only when the worker was healthy, and records the session as error/crash when a termination was already counted.
Prompt for AI agents
Check if this issue is valid — if so, understand the root cause and fix it. At crates/monty-pool/src/checkout.rs, line 1322:
<comment>A checkout whose worker crashes mid-turn is reported two inconsistent ways: the worker termination shows reason `crash`, but the session lifetime (`monty.pool.session.duration`) is recorded as `abandoned` because `Drop::drop` fires `record_finish("abandoned")` whenever `finish` was never called. That collapses "the worker died" and "the caller chose to drop a live session" into one outcome, which weakens the session-outcome signal this PR is adding. Consider tracking a `finished`/`terminated` flag on the Checkout so the drop path records `abandoned` only when the worker was healthy, and records the session as `error`/`crash` when a termination was already counted.</comment>
<file context>
@@ -1281,8 +1315,11 @@ impl Drop for Checkout {
self.pool.release_capacity();
}
+ #[cfg(feature = "telemetry")]
+ self.record_finish("abandoned");
}
}
</file context>
Spans describe one session; they cannot answer whether the fleet is saturated, how often workers die, or how much of its duration budget a typical run uses. Add the aggregate side: five pool-health instruments (worker gauge, checkout wait, spawn cost, terminations by reason, session lifetime) and eleven per-turn ones, recorded by a `TurnMetrics` state machine that mirrors the protocol the way `telemetry::Recorder` does for spans — separate from it, because metrics must also cover untraced checkouts. `monty.run.duration` minus `monty.run.execution_time` is time the host spent answering suspensions, which is where latency usually turns out to be. Attribute cardinality is enforced rather than hoped for: a function name is recorded only when the host resolved it, `exc_type` round-trips through `ExcType` and collapses to `other` otherwise, and no path reaches an attribute — sandboxed code must not be able to mint time series. Measurements reach hosts two ways. A foreign SDK gets them through `TelemetryAdapter::record_metric`, which defaults to a no-op so adapters written before metrics keep working and TELEMETRY_ADAPTER_VERSION stays 1; the Python bridge probes for the method, the Node bridge emits a `metric` event kind. A Rust host uses `Metrics::for_logfire` instead and gets real instruments on its own meter, with exponential histogram buckets rather than the SDK defaults that would put every monty turn in one bucket. The worker gauge is a gauge, not an up/down counter: one decrement missed on an error path would skew an up/down counter for the process's life. Recording never happens under the pool mutex, since it reaches into the host SDK and, for Python, its GIL. Also run `cargo test -p monty-pool` with `telemetry-adapter` enabled in the Makefile and CI, without which none of this — nor the existing telemetry tests — is covered. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_0177dP9KE9Son2yHh3vgtMim
The name described the feature exactly while everything it gated existed to feed a foreign SDK across a bridge. It no longer does: `Metrics::for_logfire` and `TelemetryContext::for_logfire` are native Rust paths with no adapter in them, so monty-server enables a feature called `telemetry-adapter` precisely in order not to implement an adapter. The feature gates all telemetry in the crate — spans, metrics, both delivery paths — which is what it should be called, and matches monty-runtime's existing `telemetry`. `telemetry-adapter` stays as an alias: this crate is published and is pinned by git rev elsewhere, so the old name keeps those consumers building until they move. The `telemetry_adapter` module and its types keep their names, being genuinely about the adapter. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_0177dP9KE9Son2yHh3vgtMim
… names
The called function's name was recorded on every host round-trip except
`not_found`, and a script can mint one name per call: calling a method a
host object does not have raises `AttributeError` there, which comes back
as `error` rather than `not_found`, so a loop over `getattr(obj,
f'method_{i}')()` bought a time series each. Restricting it to outcomes
that "prove" resolution would not have fixed it either — a host whose
lookup is a callable resolves any name at all — so the attribute is gone,
and the rule is now absolute: no value the sandbox controls becomes an
attribute. The only name left is an os call's, which comes from the
protocol's oneof.
With that settled, the catalogue itself:
- the instrument definitions lead the file — they are what a reader is
looking for, and every attribute's closed set is visible in one place
- `WORKERS` (a gauge split by `state`) becomes `LIVE_WORKERS`, a plain
count, so that "idle" means one thing here
- `IDLE_WORKERS` counts workers blocked on the host rather than running
code. It needs state shared across a pool's workers, so `Metrics` grows
an `AtomicUsize`, and `pending` is now written and cleared in one place
each (plus a `Drop`) so the gauge cannot drift from what it describes
- `HOST_CALL` and `OS_CALL` merge into `EXT_CALL`: one round-trip
histogram, `kind` telling the suspensions apart
- `SPAWN_DURATION`, `RUN_BUDGET`, `OS_IO` and `ERRORS` are dropped, with
the helpers that fed them
`SuspensionKind` also gains one variant per suspension the protocol has,
replacing a two-variant enum that kept its real discriminant in a string
beside it.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_0177dP9KE9Son2yHh3vgtMim
- Gate the `Metrics` import in monty-pool's lib.rs so the crate builds without the `telemetry` feature, and add a featureless `cargo check` of monty-proto and monty-pool to the CI lint job so it stays that way. - Total the live-worker gauge over every pool sharing one `Metrics`: the adapter handle now hands out one shared recorder, and each pool publishes deltas through a `LiveWorkersGauge` whose drop zeroes its share — per-pool series would clash (last-write-wins) and go stale. - Record subprocess sent frames body-only, matching the other three transport/direction combinations of `monty.wire.frame.bytes`. - Update the Python and JS telemetry tests to the reshaped metric catalogue (`monty.pool.workers.live`; no spawn-duration instrument). - Tighten the two `for_logfire` docstrings. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01WBuTusg2anZHSNSpmq5Fv8
fd2bccc to
5c57b30
Compare
Dismissing prior approval to re-evaluate 5c57b30
- Re-base the execution-clock ratchet from a load turn's reply: the stamp
is the restored session's cumulative clock, spent in another process,
so the next run records only its own delta instead of the whole
restored history.
- End an open load turn when a restored feed re-raises its suspension,
so the host round-trip is not billed to `monty.turn.duration{load}`.
- An error answering any open housekeeping turn is that turn's outcome,
not a run's: no more fake `monty.run.execution_time` samples from a
failed load/install_dependencies.
- Publish the worker gauges through `record_stable`, which re-records
until the value it recorded is still current: racing publishes could
otherwise land out of order and stick until the next transition, which
may never come. Still lock-free across the host-SDK call.
- Count idle workers as terminated (`closed`) when a pool is dropped
without `close()`, a supported shutdown that under-reported turnover.
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01WBuTusg2anZHSNSpmq5Fv8
Dismissing prior approval to re-evaluate c5f9783
There was a problem hiding this comment.
2 issues found across 3 files (changes from recent commits).
Prompt for AI agents (unresolved issues)
Check if these issues are valid — if so, understand the root cause of each and fix them. If appropriate, use sub-agents to investigate and fix each issue separately.
<file name="crates/monty-pool/src/pool.rs">
<violation number="1" location="crates/monty-pool/src/pool.rs:346">
P2: Pool-drop termination metrics call the host adapter while holding `state`; snapshot `idle.len()` before the loop so adapter/GIL work happens after unlocking.</violation>
</file>
<file name="crates/monty-pool/src/telemetry/metrics.rs">
<violation number="1" location="crates/monty-pool/src/telemetry/metrics.rs:342">
P3: `record_stable` retries in an unbounded loop, and on every pass it records into the host metrics SDK (and, for the Logfire sink, takes the instruments read lock). If the shared gauge atomic keeps changing between the `record` call and the closing load (many workers blocking/unblocking at once, or several pools sharing one `Metrics`), a thread can spin through many SDK interactions with no bound. In practice gauge transitions are infrequent so this is unlikely to bite, but adding an iteration cap (record the loaded value and bail after a couple of stale corrections) would bound the worst case without losing the self-correcting behavior.</violation>
</file>
Reply with feedback, questions, or to request a fix.
Re-trigger cubic
| for _ in 0..lock_ignore_poison(&self.state).idle.len() { | ||
| self.count_termination("closed"); | ||
| } |
There was a problem hiding this comment.
P2: Pool-drop termination metrics call the host adapter while holding state; snapshot idle.len() before the loop so adapter/GIL work happens after unlocking.
Prompt for AI agents
Check if this issue is valid — if so, understand the root cause and fix it. At crates/monty-pool/src/pool.rs, line 346:
<comment>Pool-drop termination metrics call the host adapter while holding `state`; snapshot `idle.len()` before the loop so adapter/GIL work happens after unlocking.</comment>
<file context>
@@ -336,6 +336,19 @@ impl PoolInner {
+ /// that path does not under-report worker turnover. (`close` drains the
+ /// idle queue and counts, so nothing is counted twice.)
+ fn drop(&mut self) {
+ for _ in 0..lock_ignore_poison(&self.state).idle.len() {
+ self.count_termination("closed");
+ }
</file context>
| for _ in 0..lock_ignore_poison(&self.state).idle.len() { | |
| self.count_termination("closed"); | |
| } | |
| let idle_workers = lock_ignore_poison(&self.state).idle.len(); | |
| for _ in 0..idle_workers { | |
| self.count_termination("closed"); | |
| } |
| /// across the call into its SDK (the deadlock the pool avoids everywhere). | ||
| fn record_stable<T: PartialEq + Copy>(load: impl Fn() -> T, record: impl Fn(T)) { | ||
| let mut value = load(); | ||
| loop { |
There was a problem hiding this comment.
P3: record_stable retries in an unbounded loop, and on every pass it records into the host metrics SDK (and, for the Logfire sink, takes the instruments read lock). If the shared gauge atomic keeps changing between the record call and the closing load (many workers blocking/unblocking at once, or several pools sharing one Metrics), a thread can spin through many SDK interactions with no bound. In practice gauge transitions are infrequent so this is unlikely to bite, but adding an iteration cap (record the loaded value and bail after a couple of stale corrections) would bound the worst case without losing the self-correcting behavior.
Prompt for AI agents
Check if this issue is valid — if so, understand the root cause and fix it. At crates/monty-pool/src/telemetry/metrics.rs, line 342:
<comment>`record_stable` retries in an unbounded loop, and on every pass it records into the host metrics SDK (and, for the Logfire sink, takes the instruments read lock). If the shared gauge atomic keeps changing between the `record` call and the closing load (many workers blocking/unblocking at once, or several pools sharing one `Metrics`), a thread can spin through many SDK interactions with no bound. In practice gauge transitions are infrequent so this is unlikely to bite, but adding an iteration cap (record the loaded value and bail after a couple of stale corrections) would bound the worst case without losing the self-correcting behavior.</comment>
<file context>
@@ -329,6 +331,24 @@ fn to_isize(n: usize) -> isize {
+/// across the call into its SDK (the deadlock the pool avoids everywhere).
+fn record_stable<T: PartialEq + Copy>(load: impl Fn() -> T, record: impl Fn(T)) {
+ let mut value = load();
+ loop {
+ record(value);
+ let current = load();
</file context>
|
(Written by claude) Security reviewScope: the whole branch diff, weighted toward host/parent code, with a specific look at whether the new metrics code can cause resource exhaustion. The cardinality question is handled — this was the main risk and it's closedEvery attribute recorded is a closed set fixed in Finding 1 — pool mutex held across host-adapter (GIL) calls
for _ in 0..lock_ignore_poison(&self.state).idle.len() {
self.count_termination("closed");
}Rust extends the Trigger: dropping a Finding 2 —
|
| workers | sink latency | suspensions | idle-gauge records | amplification |
|---|---|---|---|---|
| 8 | ~0 | 2,400 | 5,814 | 1.21× |
| 16 | 0.5 ms | 4,800 | 32,681 | 3.40× |
It's a positive-feedback shape — the slower the host's sink, the more retries, which loads the sink further — and 0.5 ms is not pessimistic: I measured 0.5–2.4 ms per bridge call whenever any host thread is CPU-busy in Python. Bounding the retries (2–3) keeps the self-correcting behaviour without the tail. Also raised by cubic (P3), unresolved.
Finding 3 — metrics roughly triple sandbox-controlled host-callback traffic (documented class, new magnitude)
Every frame now records on the pool's runtime thread; a printed line costs two record_metric calls (monty.wire.frame.bytes, monty.print.bytes) on top of the existing per-print log. 20,000 × print('x') with a telemetry adapter installed produced 40,019 metric calls + 20,000 log calls. Wall time for that feed, Python binding:
| no adapter | main + adapter |
this branch + adapter | |
|---|---|---|---|
| host thread idle | 0.067 s | 0.19 s | 0.23 s |
| one host thread running plain Python | 0.95 s | 124.8 s | 143.8 s |
The 130× cliff is GIL handoff latency, is pre-existing, and is already written down in limitations/pool-architecture.md (which this PR correctly updates to cover measurements). What's new is that the per-frame instruments scale with sandbox output rate rather than with turns — they're the only instruments that do. If you want a lever, sampling or a per-turn aggregate for monty.wire.frame.bytes / monty.print.bytes would remove the sandbox's ability to set the host callback rate, at no cost to the other twelve instruments.
Checked and clean
- Gauge arithmetic under concurrency:
LiveWorkersGauge::record's swap-then-fetch_addtelescopes correctly however the two pools interleave;to_isizesaturates;Shared.idleincrements and decrements are balanced through the singletake_pendingpath (AtomicUsizecan't underflow from a reachable state, and would saturate rather than wrap if it did). - JS bridge queue overflow → permanent telemetry disable: I expected metrics to fill napi's 1024-slot threadsafe queue and trip the one-way
disabledflag, silencing telemetry process-wide. Did not reproduce: 200,000 printed lines with the JS event loop deliberately blocked for 4 s queued 400,015 metric + 200,004 span events, host RSS stayed ~100 MB, and a subsequent session still produced spans. (Both bindings pass an unparented context whencaptureContextreturns nothing, so there is no previously-free untraced path that metrics newly make expensive.) worker.rsframe-length bookkeeping:send_buf.len() - 4cannot underflow —encode_framed_intoclears and writes the 4-byte prefix before the body, and errors return before the subtraction.- Reference/lifecycle counting in
checkout.rs:startedis taken by whichever offinish/Dropruns first, so a session is recorded once;close()drainsidlebeforeDropcounts it, so terminations aren't double-counted. - No
unsafe, no new allocation path that bypassesResourceTracker(nothing sandbox-sized is built host-side;close_suspension's 2–3 element attributeVecis the only per-event allocation), no newunwrap/expectreachable from sandboxed input.
Unrelated trap I hit, in case it bites anyone else: crates/monty-js/ts/binary.ts prefers the installed @pydantic/monty-<platform> npm package over the workspace build, so after make install-js the JS tests run a published monty binary against the locally built addon and fail with ChildEvent.kind: invalid wire type: Varint. MONTY_BIN=<workspace>/target/debug/monty fixes it. Not a branch issue, but it looks alarmingly like a protocol desync.
|
@davidhewitt I need your help on this once you're back. |
2 participants
Spans describe one session; they cannot answer whether the fleet is saturated, how often workers die, or how much of its duration budget a typical run uses. Add the aggregate side: five pool-health instruments (worker gauge, checkout wait, spawn cost, terminations by reason, session lifetime) and eleven per-turn ones, recorded by a
TurnMetricsstate machine that mirrors the protocol the waytelemetry::Recorderdoes for spans — separate from it, because metrics must also cover untraced checkouts.monty.run.durationminusmonty.run.execution_timeis time the host spent answering suspensions, which is where latency usually turns out to be. Attribute cardinality is enforced rather than hoped for: a function name is recorded only when the host resolved it,exc_typeround-trips throughExcTypeand collapses tootherotherwise, and no path reaches an attribute — sandboxed code must not be able to mint time series.Measurements reach hosts two ways. A foreign SDK gets them through
TelemetryAdapter::record_metric, which defaults to a no-op so adapters written before metrics keep working and TELEMETRY_ADAPTER_VERSION stays 1; the Python bridge probes for the method, the Node bridge emits ametricevent kind. A Rust host usesMetrics::for_logfireinstead and gets real instruments on its own meter, with exponential histogram buckets rather than the SDK defaults that would put every monty turn in one bucket.The worker gauge is a gauge, not an up/down counter: one decrement missed on an error path would skew an up/down counter for the process's life. Recording never happens under the pool mutex, since it reaches into the host SDK and, for Python, its GIL.
Also run
cargo test -p monty-poolwithtelemetry-adapterenabled in the Makefile and CI, without which none of this — nor the existing telemetry tests — is covered.Claude-Session: https://claude.ai/code/session_0177dP9KE9Son2yHh3vgtMim
Summary by cubic
Add pool-wide and per-turn metrics to
monty-pool, recorded on every checkout and delivered through the telemetry adapter or native meters. The catalog is closed to sandboxed values, adds live/idle worker gauges, and a single external-call histogram; fixes ensure accurate timing after restores and stable, correct gauges.Bug Fixes
monty.turn.duration{load}.monty.run.execution_timesamples.close().Migration
telemetry-adapter->telemetry(alias kept).monty-js/monty-pythonnow depend onmonty-poolwithtelemetry.PoolConfig.metricsadded;monty-js/monty-pythonwire it from the installed adapter. Rust hosts setPoolConfig.metrics = Metrics::for_logfire(...)(or useTelemetryAdapterHandle::metrics).TelemetryAdapter::record_metricis optional (no-op by default). Node emits{ kind: 'metric' }asTelemetryMetricEvent; Python probesrecord_metric.TELEMETRY_ADAPTER_VERSIONstays 1.Written for commit c5f9783. Summary will update on new commits.