fix: stabilize attach JSON timing snapshot (#385)

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)
2026-10-10 03:30:59 +00:00 · 2026-05-24 13:09:09 -04:00 · 2026-05-24 13:09:09 -04:00 · 6a23014f0b
commit 6a23014f0b
parent 61e26a6bff
4 changed files with 83 additions and 81 deletions
--- 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]",
--- 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 -----
    "#);
 }
--- 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 -----
--- 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]",