From 6a23014f0bec59628a311b92ef6ad02c5e3b7bc3 Mon Sep 17 00:00:00 2001 From: Bryan Helmkamp <19+brynary@users.noreply.github.com> Date: Sun, 24 May 2026 13:09:09 -0400 Subject: [PATCH] fix: stabilize attach JSON timing snapshot (#385) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Fixes the flaky `attach_json_errors_without_prompting_for_human_input` snapshot by moving elapsed JSON duration redaction into the shared `fabro-test` snapshot filters. `duration_ms`, `wall_time_ms`, `inference_time_ms`, `tool_time_ms`, and `active_time_ms` now use one common normalization path, and the attach, wait, and events integration snapshots use that shared helper instead of hand-rolled per-test regexes. This keeps snapshots focused on event shape and command behavior rather than exact runtime timing, while leaving exact timing relationships to direct assertions in lower-level tests. Verified with `cargo nextest run -p fabro-test`, `cargo nextest run -p fabro-cli --test it cmd::attach`, `cargo nextest run -p fabro-cli --test it cmd::wait`, `cargo nextest run -p fabro-cli --test it cmd::events`, `cargo +nightly-2026-04-14 fmt --check --all`, and `cargo +nightly-2026-04-14 clippy -p fabro-test -p fabro-cli --test it -- -D warnings`. --- [![Compound Engineering](https://img.shields.io/badge/Compound_Engineering-6366f1)](https://github.com/EveryInc/compound-engineering-plugin) 🤖 Generated with GPT-5 (context unknown, reasoning effort unknown) via [Codex](https://openai.com/codex) --- lib/crates/fabro-cli/tests/it/cmd/attach.rs | 86 +++++++++++---------- lib/crates/fabro-cli/tests/it/cmd/events.rs | 18 ++--- lib/crates/fabro-cli/tests/it/cmd/wait.rs | 28 ++----- lib/crates/fabro-test/src/lib.rs | 32 +++++++- 4 files changed, 83 insertions(+), 81 deletions(-) diff --git a/lib/crates/fabro-cli/tests/it/cmd/attach.rs b/lib/crates/fabro-cli/tests/it/cmd/attach.rs index 4bf0d4759..04556ad4b 100644 --- a/lib/crates/fabro-cli/tests/it/cmd/attach.rs +++ b/lib/crates/fabro-cli/tests/it/cmd/attach.rs @@ -64,6 +64,45 @@ fn format_output_snapshot(output: &Output, filters: &[(String, String)]) -> Stri ) } +fn normalize_attach_json_progress_event(mut event: Value) -> Value { + if let Some(properties) = event.get_mut("properties").and_then(Value::as_object_mut) { + if properties.contains_key("manifest_blob") { + properties.insert( + "manifest_blob".to_string(), + Value::String("[BLOB_ID]".to_string()), + ); + } + if properties.contains_key("definition_blob") { + properties.insert( + "definition_blob".to_string(), + Value::String("[BLOB_ID]".to_string()), + ); + } + } + // Strip v2-shape server/version fields that the bridge emits, + // since the test fixture's socket path is randomised per run. + if let Some(settings) = event + .pointer_mut("/properties/settings") + .and_then(Value::as_object_mut) + { + settings.remove("_version"); + settings.remove("server"); + settings.remove("version"); + } + if let Some(target) = event + .pointer_mut("/properties/settings/cli/target") + .and_then(Value::as_object_mut) + { + if target.contains_key("path") { + target.insert( + "path".to_string(), + Value::String("[CLI_SOCKET]".to_string()), + ); + } + } + event +} + fn wait_for_output_signal( child: &mut std::process::Child, stdout: &mut impl Read, @@ -734,44 +773,7 @@ fn attach_json_errors_without_prompting_for_human_input() { .lines() .filter(|line| !line.trim().is_empty()) .map(|line| serde_json::from_str(line).expect("attach JSON output should be JSONL")) - .map(|mut event: Value| { - if let Some(properties) = event.get_mut("properties").and_then(Value::as_object_mut) { - if properties.contains_key("manifest_blob") { - properties.insert( - "manifest_blob".to_string(), - Value::String("[BLOB_ID]".to_string()), - ); - } - if properties.contains_key("definition_blob") { - properties.insert( - "definition_blob".to_string(), - Value::String("[BLOB_ID]".to_string()), - ); - } - } - // Strip v2-shape server/version fields that the bridge emits, - // since the test fixture's socket path is randomised per run. - if let Some(settings) = event - .pointer_mut("/properties/settings") - .and_then(Value::as_object_mut) - { - settings.remove("_version"); - settings.remove("server"); - settings.remove("version"); - } - if let Some(target) = event - .pointer_mut("/properties/settings/cli/target") - .and_then(Value::as_object_mut) - { - if target.contains_key("path") { - target.insert( - "path".to_string(), - Value::String("[CLI_SOCKET]".to_string()), - ); - } - } - event - }) + .map(normalize_attach_json_progress_event) .collect(); fabro_json_snapshot!(context, &progress, @r#" [ @@ -1195,10 +1197,10 @@ fn attach_json_errors_without_prompting_for_human_input() { }, "status": "succeeded", "timing": { - "active_time_ms": 0, - "inference_time_ms": 0, - "tool_time_ms": 0, - "wall_time_ms": 0 + "active_time_ms": "[ACTIVE_TIME_MS]", + "inference_time_ms": "[INFERENCE_TIME_MS]", + "tool_time_ms": "[TOOL_TIME_MS]", + "wall_time_ms": "[WALL_TIME_MS]" } }, "run_id": "[ULID]", diff --git a/lib/crates/fabro-cli/tests/it/cmd/events.rs b/lib/crates/fabro-cli/tests/it/cmd/events.rs index 13c798aaa..2a853d863 100644 --- a/lib/crates/fabro-cli/tests/it/cmd/events.rs +++ b/lib/crates/fabro-cli/tests/it/cmd/events.rs @@ -1,4 +1,4 @@ -use fabro_test::{fabro_snapshot, test_context}; +use fabro_test::{fabro_snapshot, json_elapsed_ms_snapshot_filters, test_context}; use serde_json::Value; use super::support::{setup_detached_dry_run, setup_seeded_completed_dry_run}; @@ -106,15 +106,11 @@ fn events_completed_run_reads_store_without_progress_jsonl() { let context = test_context!(); let run = setup_seeded_completed_dry_run(&context); - let mut filters = context.filters(); + let mut filters = json_elapsed_ms_snapshot_filters(context.filters()); filters.push(( r"\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}(?:\.\d+)?Z".to_string(), "[TIMESTAMP]".to_string(), )); - filters.push(( - r#""duration_ms":\s*\d+"#.to_string(), - r#""duration_ms": [DURATION_MS]"#.to_string(), - )); filters.push(( r#""id":"[0-9a-f-]+""#.to_string(), r#""id":"[EVENT_ID]""#.to_string(), @@ -132,7 +128,7 @@ fn events_completed_run_reads_store_without_progress_jsonl() { exit_code: 0 ----- stdout ----- {"actor":{"kind":"worker","run_id":"[ULID]"},"event":"sandbox.stop.started","id":"[EVENT_ID]","properties":{"provider":"local"},"run_id":"[ULID]","ts":"[TIMESTAMP]"} - {"actor":{"kind":"worker","run_id":"[ULID]"},"event":"sandbox.stop.completed","id":"[EVENT_ID]","properties":{"duration_ms": [DURATION_MS],"provider":"local"},"run_id":"[ULID]","ts":"[TIMESTAMP]"} + {"actor":{"kind":"worker","run_id":"[ULID]"},"event":"sandbox.stop.completed","id":"[EVENT_ID]","properties":{"duration_ms":"[DURATION_MS]","provider":"local"},"run_id":"[ULID]","ts":"[TIMESTAMP]"} ----- stderr ----- "#); } @@ -141,15 +137,11 @@ fn events_completed_run_reads_store_without_progress_jsonl() { fn events_tail_limits_output() { let context = test_context!(); let run = setup_seeded_completed_dry_run(&context); - let mut filters = context.filters(); + let mut filters = json_elapsed_ms_snapshot_filters(context.filters()); filters.push(( r"\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}(?:\.\d+)?Z".to_string(), "[TIMESTAMP]".to_string(), )); - filters.push(( - r#""duration_ms":\s*\d+"#.to_string(), - r#""duration_ms": [DURATION_MS]"#.to_string(), - )); filters.push(( r#""id":"[0-9a-f-]+""#.to_string(), r#""id":"[EVENT_ID]""#.to_string(), @@ -166,7 +158,7 @@ fn events_tail_limits_output() { exit_code: 0 ----- stdout ----- {"actor":{"kind":"worker","run_id":"[ULID]"},"event":"sandbox.stop.started","id":"[EVENT_ID]","properties":{"provider":"local"},"run_id":"[ULID]","ts":"[TIMESTAMP]"} - {"actor":{"kind":"worker","run_id":"[ULID]"},"event":"sandbox.stop.completed","id":"[EVENT_ID]","properties":{"duration_ms": [DURATION_MS],"provider":"local"},"run_id":"[ULID]","ts":"[TIMESTAMP]"} + {"actor":{"kind":"worker","run_id":"[ULID]"},"event":"sandbox.stop.completed","id":"[EVENT_ID]","properties":{"duration_ms":"[DURATION_MS]","provider":"local"},"run_id":"[ULID]","ts":"[TIMESTAMP]"} ----- stderr ----- "#); } diff --git a/lib/crates/fabro-cli/tests/it/cmd/wait.rs b/lib/crates/fabro-cli/tests/it/cmd/wait.rs index 792b78284..bf0a2e1b1 100644 --- a/lib/crates/fabro-cli/tests/it/cmd/wait.rs +++ b/lib/crates/fabro-cli/tests/it/cmd/wait.rs @@ -1,4 +1,4 @@ -use fabro_test::{fabro_snapshot, test_context}; +use fabro_test::{fabro_snapshot, json_elapsed_ms_snapshot_filters, test_context}; use httpmock::MockServer; use serde_json::json; @@ -94,23 +94,7 @@ fn wait_completed_run_reads_store_without_status_or_conclusion_files() { fn wait_completed_run_json_outputs_status_and_duration() { let context = test_context!(); let run = setup_seeded_completed_dry_run(&context); - let mut filters = context.filters(); - filters.push(( - r#""wall_time_ms":\s*\d+"#.to_string(), - r#""wall_time_ms": [WALL_TIME_MS]"#.to_string(), - )); - filters.push(( - r#""inference_time_ms":\s*\d+"#.to_string(), - r#""inference_time_ms": [INFERENCE_TIME_MS]"#.to_string(), - )); - filters.push(( - r#""tool_time_ms":\s*\d+"#.to_string(), - r#""tool_time_ms": [TOOL_TIME_MS]"#.to_string(), - )); - filters.push(( - r#""active_time_ms":\s*\d+"#.to_string(), - r#""active_time_ms": [ACTIVE_TIME_MS]"#.to_string(), - )); + let filters = json_elapsed_ms_snapshot_filters(context.filters()); let mut cmd = context.command(); cmd.args(["wait", "--json", &run.run_id]); @@ -122,10 +106,10 @@ fn wait_completed_run_json_outputs_status_and_duration() { "run_id": "[ULID]", "status": "succeeded", "timing": { - "wall_time_ms": [WALL_TIME_MS], - "inference_time_ms": [INFERENCE_TIME_MS], - "tool_time_ms": [TOOL_TIME_MS], - "active_time_ms": [ACTIVE_TIME_MS] + "wall_time_ms": "[WALL_TIME_MS]", + "inference_time_ms": "[INFERENCE_TIME_MS]", + "tool_time_ms": "[TOOL_TIME_MS]", + "active_time_ms": "[ACTIVE_TIME_MS]" } } ----- stderr ----- diff --git a/lib/crates/fabro-test/src/lib.rs b/lib/crates/fabro-test/src/lib.rs index 8d90c1a3f..9dd283d68 100644 --- a/lib/crates/fabro-test/src/lib.rs +++ b/lib/crates/fabro-test/src/lib.rs @@ -1874,6 +1874,25 @@ where source.snapshot_filters() } +/// Add JSON elapsed-duration normalizations to a snapshot filter set. +pub fn json_elapsed_ms_snapshot_filters( + mut filters: Vec<(String, String)>, +) -> Vec<(String, String)> { + for (field, replacement) in [ + ("duration_ms", "[DURATION_MS]"), + ("wall_time_ms", "[WALL_TIME_MS]"), + ("inference_time_ms", "[INFERENCE_TIME_MS]"), + ("tool_time_ms", "[TOOL_TIME_MS]"), + ("active_time_ms", "[ACTIVE_TIME_MS]"), + ] { + filters.push(( + format!(r#""{field}"(\s*:\s*)\d+"#), + format!(r#""{field}"$1"{replacement}""#), + )); + } + filters +} + /// Add JSON-specific normalizations to a snapshot filter set. pub fn json_snapshot_filters(mut filters: Vec<(String, String)>) -> Vec<(String, String)> { filters.push(( @@ -1884,10 +1903,7 @@ pub fn json_snapshot_filters(mut filters: Vec<(String, String)>) -> Vec<(String, r#""id":\s*"[0-9a-f-]+""#.to_string(), r#""id": "[EVENT_ID]""#.to_string(), )); - filters.push(( - r#""duration_ms":\s*\d+"#.to_string(), - r#""duration_ms": "[DURATION_MS]""#.to_string(), - )); + filters = json_elapsed_ms_snapshot_filters(filters); filters.push(( r#""manifest_blob":\s*"[0-9a-f]{64}""#.to_string(), r#""manifest_blob": "[BLOB_ID]""#.to_string(), @@ -2384,6 +2400,10 @@ mod tests { "id": "a68e40fe-0877-48a3-913f-6339b0d198cc", "created_at": "2026-04-24T12:34:56.789Z", "duration_ms": 12345, + "wall_time_ms": 23456, + "inference_time_ms": 34567, + "tool_time_ms": 45678, + "active_time_ms": 80245, "manifest_blob": "0123456789abcdef0123456789abcdef0123456789abcdef0123456789abcdef", "definition_blob": "abcdef0123456789abcdef0123456789abcdef0123456789abcdef0123456789", "run_dir": "[STORAGE_DIR]/scratch/20260424-01ARZ3NDEKTSV4RRFFQ69G5FAV", @@ -2397,6 +2417,10 @@ mod tests { "id": "[EVENT_ID]", "created_at": "[TIMESTAMP]", "duration_ms": "[DURATION_MS]", + "wall_time_ms": "[WALL_TIME_MS]", + "inference_time_ms": "[INFERENCE_TIME_MS]", + "tool_time_ms": "[TOOL_TIME_MS]", + "active_time_ms": "[ACTIVE_TIME_MS]", "manifest_blob": "[BLOB_ID]", "definition_blob": "[BLOB_ID]", "run_dir": "[RUN_DIR]",