From 5b6add4a5fbcdb9877fbcdfba99f0b929912a5cb Mon Sep 17 00:00:00 2001
From: ualtinok <94532+ualtinok@users.noreply.github.com>
Date: Tue, 3 Nov 2026 04:50:53 +0100
Subject: [PATCH 1/8] mason: expose slow registry setup in base retention
 regression

Co-authored-by: alfonso-aft <289616620+alfonso-aft@users.noreply.github.com>
---
 crates/aft/src/storage_retention.rs | 16 ++++++++++++++++
 1 file changed, 16 insertions(+)

diff --git a/crates/aft/src/storage_retention.rs b/crates/aft/src/storage_retention.rs
index ff05dd9c5..b08aa9d90 100644
--- a/crates/aft/src/storage_retention.rs
+++ b/crates/aft/src/storage_retention.rs
@@ -6520,6 +6520,8 @@ fn collect_v3_family_at(
     // The final measurement still settles dead reservations and never records
     // a partial total. No publication is admitted through this handle.
     let mut registry = RegistryWriter::open_for_barrier(storage, family, &lock).map_err(v3)?;
+    #[cfg(test)]
+    test_hook(storage, "v3-registry-opened");
     // Base references get the first turn, before member cleanup or accounting
     // can consume the visit. All three phases share the reservation lock.
     if !cancelled()
@@ -16555,6 +16557,19 @@ mod v3_base_reference_collector_tests {
             .unwrap(),
         );
         drop(composed);
+        // A slow registry open can exhaust a visit before the reference sweep
+        // starts, even though later visits can still reclaim the unused base.
+        let delay_first_open = std::sync::atomic::AtomicBool::new(true);
+        let _slow_open = observe_test_hook(
+            storage.path(),
+            Arc::new(move |step| {
+                if step == "v3-registry-opened"
+                    && delay_first_open.swap(false, std::sync::atomic::Ordering::SeqCst)
+                {
+                    std::thread::sleep(Duration::from_millis(500));
+                }
+            }),
+        );
         for sweep in 0..2 {
             v3::set_walk_delay_for_test(Duration::from_millis(500));
             let mut report = SweepReport::default();
@@ -16569,6 +16584,7 @@ mod v3_base_reference_collector_tests {
             );
             v3::set_walk_delay_for_test(Duration::ZERO);
             result.unwrap();
+            eprintln!("collector visit {}: {report:?}", sweep + 1);
             assert!(report.errors.is_empty(), "{report:?}");
             assert_eq!(
                 report.skipped_families,

From 19bd1513dc459e280f94cc61d4127407ded84e09 Mon Sep 17 00:00:00 2001
From: ualtinok <94532+ualtinok@users.noreply.github.com>
Date: Tue, 3 Nov 2026 04:56:29 +0100
Subject: [PATCH 2/8] mason: wait for budgeted base reclamation across
 collector visits

The regression used to require two collector visits to reclaim a base, but lock acquisition and registry setup share the visit budget and can defer a reference sweep entirely. Keep the 250 ms budget and forced owed accounting; retry at most 16 visits, retaining pin/reference checks on every visit and verifying the directory is removed. Inject one slow registry open so the test covers a deferred reference sweep instead of relying on a fast runner.

Co-authored-by: alfonso-aft <289616620+alfonso-aft@users.noreply.github.com>
---
 crates/aft/src/storage_retention.rs | 29 ++++++++++++++++++++++++-----
 1 file changed, 24 insertions(+), 5 deletions(-)

diff --git a/crates/aft/src/storage_retention.rs b/crates/aft/src/storage_retention.rs
index b08aa9d90..3cc0c4e4d 100644
--- a/crates/aft/src/storage_retention.rs
+++ b/crates/aft/src/storage_retention.rs
@@ -16570,7 +16570,11 @@ mod v3_base_reference_collector_tests {
                 }
             }),
         );
-        for sweep in 0..2 {
+        // Only admitted reference sweeps advance the persisted unreferenced
+        // count. Keep the visit budget short and wait for reclamation instead
+        // of assuming that two collector visits always admit two sweeps.
+        const MAX_SWEEPS: usize = 16;
+        for sweep in 1..=MAX_SWEEPS {
             v3::set_walk_delay_for_test(Duration::from_millis(500));
             let mut report = SweepReport::default();
             let result = collect_one_v3_family(
@@ -16584,15 +16588,30 @@ mod v3_base_reference_collector_tests {
             );
             v3::set_walk_delay_for_test(Duration::ZERO);
             result.unwrap();
-            eprintln!("collector visit {}: {report:?}", sweep + 1);
             assert!(report.errors.is_empty(), "{report:?}");
             assert_eq!(
                 report.skipped_families,
                 [format!("blobs/v3/{FAMILY}: measurement_owed")]
             );
-            assert_eq!(registered(storage.path(), &unused.scope), sweep == 0);
-            assert!(registered(storage.path(), &held.scope));
-            assert!(registered(storage.path(), &referenced.scope));
+            assert!(
+                registered(storage.path(), &held.scope),
+                "visit {sweep}: {report:?}"
+            );
+            assert!(
+                registered(storage.path(), &referenced.scope),
+                "visit {sweep}: {report:?}"
+            );
+            if !registered(storage.path(), &unused.scope) {
+                eprintln!(
+                    "unused base reclaimed after {sweep} collector visits with accounting owed"
+                );
+                break;
+            }
+            assert!(
+                sweep < MAX_SWEEPS,
+                "unused base {} still registered after {MAX_SWEEPS} collector visits with accounting owed; last report: {report:?}",
+                unused.scope
+            );
         }
         assert!(!v3::view_dir(storage.path(), FAMILY, &unused.scope)
             .unwrap()

From e45522dfc495750688e5650ae54820cde6c0f272 Mon Sep 17 00:00:00 2001
From: ualtinok <94532+ualtinok@users.noreply.github.com>
Date: Tue, 3 Nov 2026 05:27:34 +0100
Subject: [PATCH 3/8] Flake batch 38: search descriptor (non_ranking)

Co-authored-by: alfonso-aft <289616620+alfonso-aft@users.noreply.github.com>
---
 .../aft-search/slice-descriptors/land-flake-batch-38.json | 8 ++++++++
 1 file changed, 8 insertions(+)
 create mode 100644 benchmarks/aft-search/slice-descriptors/land-flake-batch-38.json

diff --git a/benchmarks/aft-search/slice-descriptors/land-flake-batch-38.json b/benchmarks/aft-search/slice-descriptors/land-flake-batch-38.json
new file mode 100644
index 000000000..27e9e4466
--- /dev/null
+++ b/benchmarks/aft-search/slice-descriptors/land-flake-batch-38.json
@@ -0,0 +1,8 @@
+{
+  "fixtures": [
+    "harness-goldens"
+  ],
+  "kind": "harness",
+  "slice_class": "non_ranking",
+  "targeted_mechanism": "none"
+}

From 463dda59d3a835e276af8800866db24f87c79e87 Mon Sep 17 00:00:00 2001
From: ualtinok <94532+ualtinok@users.noreply.github.com>
Date: Tue, 3 Nov 2026 04:40:21 +0100
Subject: [PATCH 4/8] mason: instrument bounded graph read phases on Windows

Record test-only pin, zoom observation, context selection/gap/accounting, query-lock, submission, receiver-budget and completion phases. Keep the existing end-to-end assertion unchanged to diagnose the reported overrun before choosing a fix.

Co-authored-by: alfonso-aft <289616620+alfonso-aft@users.noreply.github.com>
---
 crates/aft/src/commands/configure.rs | 29 ++++++++++++++--
 crates/aft/src/commands/zoom.rs      | 10 ++++++
 crates/aft/src/context.rs            | 12 +++++++
 crates/aft/src/views/callgraph.rs    | 51 ++++++++++++++++++++++------
 4 files changed, 90 insertions(+), 12 deletions(-)

diff --git a/crates/aft/src/commands/configure.rs b/crates/aft/src/commands/configure.rs
index fca71a88d..0f1cc1de4 100644
--- a/crates/aft/src/commands/configure.rs
+++ b/crates/aft/src/commands/configure.rs
@@ -15469,9 +15469,18 @@ mod tests {
         let (entered_tx, entered_rx) = crossbeam_channel::unbounded();
         let (release_tx, release_rx) = crossbeam_channel::bounded(1);
         let (published_tx, published_rx) = crossbeam_channel::unbounded();
+        let (phase_tx, phase_rx) = crossbeam_channel::unbounded();
+        let timing_origin = Instant::now();
         let _hook = crate::storage_retention::observe_test_hook(
             &root,
             Arc::new(move |step| {
+                if step.starts_with("cg-timing:") {
+                    let _ = phase_tx.send((
+                        std::thread::current().id(),
+                        step.to_owned(),
+                        Instant::now(),
+                    ));
+                }
                 if step == "callgraph-materialize" {
                     entered_tx.send(()).unwrap();
                     release_rx.recv_timeout(Duration::from_secs(30)).unwrap();
@@ -15490,23 +15499,33 @@ mod tests {
             callers_request.clone()
         };
         let (answer_tx, answer_rx) = crossbeam_channel::unbounded();
+        let timing_ids = std::sync::atomic::AtomicUsize::new(0);
         let spawn_read = || {
             let worker_ctx = ctx.clone();
             let request = request.clone();
             let answer_tx = answer_tx.clone();
             let executor = _executor.clone();
             let root_id = crate::path_identity::ProjectRootId::from_path(&root).unwrap();
+            let timing_root = root.clone();
+            let timing_id = timing_ids.fetch_add(1, Ordering::Relaxed);
             std::thread::spawn(move || {
                 let started = Instant::now();
                 let id = request.id.clone();
                 let zoom = request.command == "zoom";
                 let run = move |ctx: &AppContext| {
+                    crate::storage_retention::test_hook(
+                        &timing_root,
+                        &format!("cg-timing:request-{timing_id}-pin-begin"),
+                    );
                     let _pin = ctx.pin_config();
-                    if zoom {
+                    crate::storage_retention::test_hook(&timing_root, "cg-timing:pin-return");
+                    let response = if zoom {
                         crate::commands::zoom::handle_zoom(&request, ctx)
                     } else {
                         crate::commands::callers::handle_callers(&request, ctx)
-                    }
+                    };
+                    crate::storage_retention::test_hook(&timing_root, "cg-timing:handler-return");
+                    response
                 };
                 let response = if let Some(executor) = executor {
                     executor
@@ -15542,6 +15561,12 @@ mod tests {
         release_tx.send(()).unwrap();
         worker.join().unwrap();
         concurrent.join().unwrap();
+        for (thread, phase, at) in phase_rx.try_iter() {
+            eprintln!(
+                "cg_timing thread={thread:?} at_us={} {phase}",
+                at.duration_since(timing_origin).as_micros()
+            );
+        }
         assert!(entered.is_ok(), "request never reached materialization");
         for bounded_answer in [first, second] {
             let answered_in_bound = bounded_answer.is_ok();
diff --git a/crates/aft/src/commands/zoom.rs b/crates/aft/src/commands/zoom.rs
index 943bd2008..c4b9b6559 100644
--- a/crates/aft/src/commands/zoom.rs
+++ b/crates/aft/src/commands/zoom.rs
@@ -1846,7 +1846,17 @@ fn zoom_one_symbol_inner(
 /// counts as that first use and can start the build.
 fn unavailable_callgraph_field(ctx: &AppContext) -> Option<serde_json::Value> {
     use crate::feature_status::{observe_callgraph_query, IndexEffective};
+    #[cfg(test)]
+    crate::storage_retention::test_hook(
+        &ctx.canonical_cache_root(),
+        "cg-timing:zoom-observe-begin",
+    );
     let observation = observe_callgraph_query(ctx);
+    #[cfg(test)]
+    crate::storage_retention::test_hook(
+        &ctx.canonical_cache_root(),
+        "cg-timing:zoom-observe-return",
+    );
     let code = match observation.effective {
         IndexEffective::Ready => return None,
         IndexEffective::Off => "callgraph_off",
diff --git a/crates/aft/src/context.rs b/crates/aft/src/context.rs
index 94831534d..717c4f461 100644
--- a/crates/aft/src/context.rs
+++ b/crates/aft/src/context.rs
@@ -13236,6 +13236,8 @@ impl AppContext {
             .lock()
             .as_ref()
             .is_some_and(|view| view.matches(&root, &storage, &family, policy));
+        #[cfg(test)]
+        crate::storage_retention::test_hook(&root, "cg-timing:context-route-ready");
         if !own_view_bound || self.callgraph_borrow.lock().is_some() {
             if let Some(borrowed) =
                 self.borrowed_callgraph_view_reader(&root, &storage, &family, policy, false)
@@ -13257,6 +13259,8 @@ impl AppContext {
                 return Some(borrowed);
             }
         }
+        #[cfg(test)]
+        crate::storage_retention::test_hook(&root, "cg-timing:context-view-select-begin");
         let view = {
             let mut slot = self.callgraph_view.lock();
             if !slot
@@ -13320,13 +13324,19 @@ impl AppContext {
             }
             slot.as_ref().unwrap().clone()
         };
+        #[cfg(test)]
+        crate::storage_retention::test_hook(&root, "cg-timing:context-view-selected");
         self.record_checkout_pending_watcher_gap();
+        #[cfg(test)]
+        crate::storage_retention::test_hook(&root, "cg-timing:context-gap-recorded");
         let result = match acquire(&view) {
             Err(error) if error.reason.contains(crate::views::trigram::BASE_CAP_BUSY) => self
                 .borrowed_callgraph_view_reader(&root, &storage, &family, policy, true)
                 .unwrap_or(Err(error)),
             result => result,
         };
+        #[cfg(test)]
+        crate::storage_retention::test_hook(&root, "cg-timing:context-view-read-return");
         if pinned_config_for(self.config_pin_key()).is_some() {
             CALLGRAPH_QUERY_READERS.with(|readers| {
                 readers
@@ -13342,6 +13352,8 @@ impl AppContext {
                 self.note_classified_view_load_failure("callgraph", &error.reason, false);
             }
         }
+        #[cfg(test)]
+        crate::storage_retention::test_hook(&root, "cg-timing:context-accounted");
         Some(result)
     }
 
diff --git a/crates/aft/src/views/callgraph.rs b/crates/aft/src/views/callgraph.rs
index d8c9f4657..3ff40836c 100644
--- a/crates/aft/src/views/callgraph.rs
+++ b/crates/aft/src/views/callgraph.rs
@@ -966,8 +966,13 @@ impl CallgraphView {
         &self,
         now: impl Fn() -> std::time::Instant,
     ) -> Result<Arc<ReadonlyCallGraphStore>, CallgraphViewError> {
+        #[cfg(test)]
+        crate::storage_retention::test_hook(&self.root, "cg-timing:view-reader-enter");
         let deadline = std::time::Instant::now() + super::contracts::CALLGRAPH_QUERY_WAIT;
-        self.reader_before(now, deadline)
+        let result = self.reader_before(now, deadline);
+        #[cfg(test)]
+        crate::storage_retention::test_hook(&self.root, "cg-timing:view-reader-return");
+        result
     }
 
     fn reader_before(
@@ -984,10 +989,12 @@ impl CallgraphView {
         }
         // Joining another request and receiving the acquisition share one
         // deadline; queued readers must not get a fresh window after the lock.
-        let mut retry = self
-            .query
-            .try_lock_until(deadline)
-            .ok_or_else(graph_building)?;
+        #[cfg(test)]
+        crate::storage_retention::test_hook(&self.root, "cg-timing:query-lock-begin");
+        let retry = self.query.try_lock_until(deadline);
+        #[cfg(test)]
+        crate::storage_retention::test_hook(&self.root, "cg-timing:query-lock-return");
+        let mut retry = retry.ok_or_else(graph_building)?;
         let mut steady = self
             .steady
             .lock()
@@ -1025,10 +1032,14 @@ impl CallgraphView {
         {
             *retry = super::contracts::LoadRetry::default();
         }
+        #[cfg(test)]
+        crate::storage_retention::test_hook(&self.root, "cg-timing:steady-update-begin");
         *steady = match &result {
             Ok((store, Some(revision))) => Some((*revision, store.clone())),
             _ => None,
         };
+        #[cfg(test)]
+        crate::storage_retention::test_hook(&self.root, "cg-timing:steady-update-return");
         let result = result.map(|(store, _)| store);
         self.ready
             .store(result.is_ok(), std::sync::atomic::Ordering::Release);
@@ -1114,6 +1125,8 @@ impl CallgraphView {
     }
 
     fn acquire_before(&self, deadline: std::time::Instant) -> ReaderAcquisition {
+        #[cfg(test)]
+        crate::storage_retention::test_hook(&self.root, "cg-timing:acquire-enter");
         let mut acquisition = self
             .acquisition
             .lock()
@@ -1145,21 +1158,39 @@ impl CallgraphView {
         if acquisition.is_none() {
             let source = self.source.clone();
             let (tx, rx) = crossbeam_channel::bounded(1);
+            #[cfg(test)]
+            crate::storage_retention::test_hook(&self.root, "cg-timing:submit-begin");
             self.owner.spawn(
                 self.current.clone(),
                 move || source.acquire_with_revision(),
                 tx,
             )?;
             #[cfg(test)]
+            crate::storage_retention::test_hook(&self.root, "cg-timing:submit-return");
+            #[cfg(test)]
             self.acquisitions
                 .fetch_add(1, std::sync::atomic::Ordering::Relaxed);
             *acquisition = Some(rx);
         }
-        match acquisition
-            .as_ref()
-            .unwrap()
-            .recv_timeout(deadline.saturating_duration_since(std::time::Instant::now()))
-        {
+        let remaining = deadline.saturating_duration_since(std::time::Instant::now());
+        #[cfg(test)]
+        crate::storage_retention::test_hook(
+            &self.root,
+            &format!(
+                "cg-timing:receive-begin budget_us={}",
+                remaining.as_micros()
+            ),
+        );
+        let received = acquisition.as_ref().unwrap().recv_timeout(remaining);
+        #[cfg(test)]
+        crate::storage_retention::test_hook(
+            &self.root,
+            match &received {
+                Err(crossbeam_channel::RecvTimeoutError::Timeout) => "cg-timing:receive-timeout",
+                _ => "cg-timing:receive-return",
+            },
+        );
+        match received {
             Ok(result) => {
                 *acquisition = None;
                 result

From 21b702ab7d9e1a7101af21cada4cd1394431c42f Mon Sep 17 00:00:00 2001
From: ualtinok <94532+ualtinok@users.noreply.github.com>
Date: Tue, 3 Nov 2026 04:41:04 +0100
Subject: [PATCH 5/8] mason: label graph-read timing by request path

Co-authored-by: alfonso-aft <289616620+alfonso-aft@users.noreply.github.com>
---
 crates/aft/src/commands/configure.rs | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/crates/aft/src/commands/configure.rs b/crates/aft/src/commands/configure.rs
index 0f1cc1de4..d7ee3c815 100644
--- a/crates/aft/src/commands/configure.rs
+++ b/crates/aft/src/commands/configure.rs
@@ -15563,7 +15563,7 @@ mod tests {
         concurrent.join().unwrap();
         for (thread, phase, at) in phase_rx.try_iter() {
             eprintln!(
-                "cg_timing thread={thread:?} at_us={} {phase}",
+                "cg_timing command={command} daemon={daemon} thread={thread:?} at_us={} {phase}",
                 at.duration_since(timing_origin).as_micros()
             );
         }

From beb7e7a102c3ae059157bcdb96ac8d4f24515010 Mon Sep 17 00:00:00 2001
From: ualtinok <94532+ualtinok@users.noreply.github.com>
Date: Tue, 3 Nov 2026 05:14:30 +0100
Subject: [PATCH 6/8] mason: assert materialization wait policy instead of
 reply wall time

Native Windows solo and parallel configure-module instrumentation did not reproduce the historical extra second: observed reader windows stayed about 3004-3007 ms, with millisecond parsing/rendering overhead. Preserve end-to-end timing as diagnostics, but prove the actual contract through unchanged absolute deadlines, remaining query/receive budgets, and timeout outcomes while the worker stays gated.

Use a cleanup-only watchdog, not a larger production timeout. Add a controlled 1250 ms post-timeout delivery gate: replies deliberately exceed the former wall-clock envelope while wait arguments and Building responses remain correct. All observers and delay controls are test-only.

Co-authored-by: alfonso-aft <289616620+alfonso-aft@users.noreply.github.com>
---
 crates/aft/src/commands/configure.rs | 149 ++++++++++++++++++++++-----
 crates/aft/src/views/callgraph.rs    |  87 +++++++++++++++-
 2 files changed, 209 insertions(+), 27 deletions(-)

diff --git a/crates/aft/src/commands/configure.rs b/crates/aft/src/commands/configure.rs
index d7ee3c815..e0c37a199 100644
--- a/crates/aft/src/commands/configure.rs
+++ b/crates/aft/src/commands/configure.rs
@@ -15380,7 +15380,11 @@ mod tests {
         );
     }
 
-    fn assert_callgraph_views_rematerialization_bounded(command: &str, daemon: bool) {
+    fn assert_callgraph_views_rematerialization_bounded(
+        command: &str,
+        daemon: bool,
+        delay_delivery: bool,
+    ) {
         let _git_env = crate::test_env::hermetic_git_env_guard();
         let _serial = crate::blob_store::v3::serial_for_test();
         let temp = tempfile::tempdir().unwrap();
@@ -15470,6 +15474,8 @@ mod tests {
         let (release_tx, release_rx) = crossbeam_channel::bounded(1);
         let (published_tx, published_rx) = crossbeam_channel::unbounded();
         let (phase_tx, phase_rx) = crossbeam_channel::unbounded();
+        let (timed_out_tx, timed_out_rx) = crossbeam_channel::unbounded();
+        let (deliver_tx, deliver_rx) = crossbeam_channel::unbounded();
         let timing_origin = Instant::now();
         let _hook = crate::storage_retention::observe_test_hook(
             &root,
@@ -15481,9 +15487,18 @@ mod tests {
                         Instant::now(),
                     ));
                 }
+                if matches!(
+                    step,
+                    "cg-timing:receive-timeout" | "cg-timing:query-lock-timeout"
+                ) {
+                    timed_out_tx.send(()).unwrap();
+                    if delay_delivery {
+                        deliver_rx.recv_timeout(Duration::from_secs(120)).unwrap();
+                    }
+                }
                 if step == "callgraph-materialize" {
                     entered_tx.send(()).unwrap();
-                    release_rx.recv_timeout(Duration::from_secs(30)).unwrap();
+                    release_rx.recv_timeout(Duration::from_secs(120)).unwrap();
                 } else if step == "callgraph-reader-acquired" {
                     let _ = published_tx.send(());
                 }
@@ -15508,23 +15523,35 @@ mod tests {
             let root_id = crate::path_identity::ProjectRootId::from_path(&root).unwrap();
             let timing_root = root.clone();
             let timing_id = timing_ids.fetch_add(1, Ordering::Relaxed);
+            let (waits_tx, waits_rx) = crossbeam_channel::bounded(1);
             std::thread::spawn(move || {
                 let started = Instant::now();
                 let id = request.id.clone();
                 let zoom = request.command == "zoom";
                 let run = move |ctx: &AppContext| {
-                    crate::storage_retention::test_hook(
-                        &timing_root,
-                        &format!("cg-timing:request-{timing_id}-pin-begin"),
-                    );
-                    let _pin = ctx.pin_config();
-                    crate::storage_retention::test_hook(&timing_root, "cg-timing:pin-return");
-                    let response = if zoom {
-                        crate::commands::zoom::handle_zoom(&request, ctx)
-                    } else {
-                        crate::commands::callers::handle_callers(&request, ctx)
-                    };
-                    crate::storage_retention::test_hook(&timing_root, "cg-timing:handler-return");
+                    let (response, waits) =
+                        crate::views::callgraph::capture_read_waits_for_test(|| {
+                            crate::storage_retention::test_hook(
+                                &timing_root,
+                                &format!("cg-timing:request-{timing_id}-pin-begin"),
+                            );
+                            let _pin = ctx.pin_config();
+                            crate::storage_retention::test_hook(
+                                &timing_root,
+                                "cg-timing:pin-return",
+                            );
+                            let response = if zoom {
+                                crate::commands::zoom::handle_zoom(&request, ctx)
+                            } else {
+                                crate::commands::callers::handle_callers(&request, ctx)
+                            };
+                            crate::storage_retention::test_hook(
+                                &timing_root,
+                                "cg-timing:handler-return",
+                            );
+                            response
+                        });
+                    waits_tx.send(waits).unwrap();
                     response
                 };
                 let response = if let Some(executor) = executor {
@@ -15546,7 +15573,10 @@ mod tests {
                 } else {
                     run(&worker_ctx)
                 };
-                answer_tx.send((started.elapsed(), response)).unwrap();
+                let waits = waits_rx.recv_timeout(Duration::from_secs(120)).unwrap();
+                answer_tx
+                    .send((started.elapsed(), response, waits))
+                    .unwrap();
             })
         };
         let worker = spawn_read();
@@ -15555,7 +15585,23 @@ mod tests {
         // A reader queued behind the first read gets the same total budget,
         // not another full wait after the first read releases the query lock.
         let concurrent = spawn_read();
-        let deadline = Instant::now() + bound + Duration::from_secs(1);
+        // This watchdog only releases stuck fixture threads. The assertions
+        // below check actual wait arguments and timeout outcomes, not dispatch
+        // or response-rendering wall time on a busy runner.
+        let deadline = Instant::now() + Duration::from_secs(120);
+        let first_timeout =
+            timed_out_rx.recv_timeout(deadline.saturating_duration_since(Instant::now()));
+        let second_timeout =
+            timed_out_rx.recv_timeout(deadline.saturating_duration_since(Instant::now()));
+        let materializer_still_gated = published_rx.is_empty();
+        let delivery_was_gated = !delay_delivery || answer_rx.is_empty();
+        if delay_delivery {
+            crossbeam_channel::after(Duration::from_millis(1250))
+                .recv()
+                .unwrap();
+            deliver_tx.send(()).unwrap();
+            deliver_tx.send(()).unwrap();
+        }
         let first = answer_rx.recv_timeout(deadline.saturating_duration_since(Instant::now()));
         let second = answer_rx.recv_timeout(deadline.saturating_duration_since(Instant::now()));
         release_tx.send(()).unwrap();
@@ -15568,14 +15614,62 @@ mod tests {
             );
         }
         assert!(entered.is_ok(), "request never reached materialization");
+        assert!(
+            first_timeout.is_ok() && second_timeout.is_ok(),
+            "a read did not time out while materialization was gated"
+        );
+        assert!(
+            materializer_still_gated,
+            "materialization finished before the timeout observations"
+        );
+        assert!(
+            delivery_was_gated,
+            "post-timeout delivery gate did not hold the reply"
+        );
         for bounded_answer in [first, second] {
-            let answered_in_bound = bounded_answer.is_ok();
-            let (elapsed, answer) = bounded_answer.unwrap_or_else(|_| answer_rx.recv().unwrap());
-            eprintln!("{command}: changed_files=64 read_ms={} bound_ms={} answered_before_release={answered_in_bound}", elapsed.as_millis(), bound.as_millis());
+            let answered_while_gated = bounded_answer.is_ok();
+            let (elapsed, answer, waits) =
+                bounded_answer.unwrap_or_else(|_| answer_rx.recv().unwrap());
+            eprintln!("{command}: changed_files=64 read_ms={} bound_ms={} answered_before_release={answered_while_gated} delayed_delivery={delay_delivery}", elapsed.as_millis(), bound.as_millis());
+            assert!(
+                answered_while_gated,
+                "read did not deliver after its bounded wait"
+            );
+            assert!(
+                !waits.is_empty(),
+                "read did not observe the materialization wait policy"
+            );
+            let wait_deadline = waits[0].deadline;
+            assert_eq!(
+                waits[0].stage,
+                crate::views::callgraph::ReadWaitStage::QueryLock
+            );
             assert!(
-                answered_in_bound,
-                "{command} waited {elapsed:?} for materialization past {bound:?}"
+                waits.iter().any(|wait| wait.timed_out),
+                "read did not observe a bounded timeout"
             );
+            for wait in waits {
+                eprintln!("cg_wait command={command} daemon={daemon} stage={:?} requested_us={} observed_us={} timed_out={}", wait.stage, wait.requested.as_micros(), wait.finished.duration_since(wait.started).as_micros(), wait.timed_out);
+                assert_eq!(
+                    wait.deadline, wait_deadline,
+                    "a wait stage reset the request deadline"
+                );
+                assert!(
+                    wait.requested <= bound,
+                    "wait requested more than the production bound: {wait:?}"
+                );
+                assert_eq!(
+                    wait.requested,
+                    wait_deadline.saturating_duration_since(wait.started),
+                    "wait did not receive only the remaining request budget"
+                );
+            }
+            if delay_delivery {
+                assert!(
+                    elapsed > bound + Duration::from_secs(1),
+                    "controlled response delay was not exercised"
+                );
+            }
             if command == "zoom" {
                 assert!(answer.success, "{:?}", answer.data);
                 assert!(answer.data.to_string().contains("export function target"));
@@ -15604,22 +15698,27 @@ mod tests {
 
     #[test]
     fn callgraph_views_rematerialization_bounds_callers_then_serves_publication() {
-        assert_callgraph_views_rematerialization_bounded("callers", false);
+        assert_callgraph_views_rematerialization_bounded("callers", false, false);
     }
 
     #[test]
     fn callgraph_views_rematerialization_bounds_zoom_then_serves_publication() {
-        assert_callgraph_views_rematerialization_bounded("zoom", false);
+        assert_callgraph_views_rematerialization_bounded("zoom", false, false);
     }
 
     #[test]
     fn callgraph_views_rematerialization_bounds_daemon_callers_then_serves_publication() {
-        assert_callgraph_views_rematerialization_bounded("callers", true);
+        assert_callgraph_views_rematerialization_bounded("callers", true, false);
     }
 
     #[test]
     fn callgraph_views_rematerialization_bounds_daemon_zoom_then_serves_publication() {
-        assert_callgraph_views_rematerialization_bounded("zoom", true);
+        assert_callgraph_views_rematerialization_bounded("zoom", true, false);
+    }
+
+    #[test]
+    fn callgraph_views_wait_bound_excludes_controlled_post_timeout_reply_delay() {
+        assert_callgraph_views_rematerialization_bounded("zoom", false, true);
     }
 
     fn assert_callgraph_acquisition_lifecycle(
diff --git a/crates/aft/src/views/callgraph.rs b/crates/aft/src/views/callgraph.rs
index 3ff40836c..7641fcc42 100644
--- a/crates/aft/src/views/callgraph.rs
+++ b/crates/aft/src/views/callgraph.rs
@@ -37,6 +37,64 @@ use super::{Manifest, ManifestEntry, RegularPlanes, RelPath};
 /// HTML headings that share a row.
 pub const PRODUCER: &str = "ruled-callgraph-v13-python-import-bindings";
 
+#[cfg(test)]
+#[derive(Clone, Copy, Debug, PartialEq, Eq)]
+pub(crate) enum ReadWaitStage {
+    QueryLock,
+    Acquisition,
+}
+
+#[cfg(test)]
+#[derive(Clone, Copy, Debug)]
+pub(crate) struct ReadWaitObservation {
+    pub stage: ReadWaitStage,
+    pub started: std::time::Instant,
+    pub deadline: std::time::Instant,
+    pub requested: std::time::Duration,
+    pub finished: std::time::Instant,
+    pub timed_out: bool,
+}
+
+#[cfg(test)]
+thread_local! {
+    static READ_WAIT_OBSERVATIONS: std::cell::RefCell<Option<Vec<ReadWaitObservation>>> = const { std::cell::RefCell::new(None) };
+}
+
+#[cfg(test)]
+struct ReadWaitCapture(Option<Vec<ReadWaitObservation>>);
+
+#[cfg(test)]
+impl Drop for ReadWaitCapture {
+    fn drop(&mut self) {
+        let previous = std::mem::replace(&mut self.0, None);
+        READ_WAIT_OBSERVATIONS.with(|slot| {
+            slot.replace(previous);
+        });
+    }
+}
+
+#[cfg(test)]
+pub(crate) fn capture_read_waits_for_test<T>(
+    read: impl FnOnce() -> T,
+) -> (T, Vec<ReadWaitObservation>) {
+    let guard = ReadWaitCapture(READ_WAIT_OBSERVATIONS.with(|slot| slot.replace(Some(Vec::new()))));
+    let result = read();
+    let observations = READ_WAIT_OBSERVATIONS
+        .with(|slot| slot.replace(None))
+        .unwrap();
+    drop(guard);
+    (result, observations)
+}
+
+#[cfg(test)]
+fn record_read_wait(observation: ReadWaitObservation) {
+    READ_WAIT_OBSERVATIONS.with(|slot| {
+        if let Some(observations) = slot.borrow_mut().as_mut() {
+            observations.push(observation);
+        }
+    });
+}
+
 #[derive(Clone, Debug)]
 pub struct CallgraphAttachment {
     payload: Arc<std::sync::Mutex<Option<Arc<[u8]>>>>,
@@ -966,9 +1024,9 @@ impl CallgraphView {
         &self,
         now: impl Fn() -> std::time::Instant,
     ) -> Result<Arc<ReadonlyCallGraphStore>, CallgraphViewError> {
+        let deadline = std::time::Instant::now() + super::contracts::CALLGRAPH_QUERY_WAIT;
         #[cfg(test)]
         crate::storage_retention::test_hook(&self.root, "cg-timing:view-reader-enter");
-        let deadline = std::time::Instant::now() + super::contracts::CALLGRAPH_QUERY_WAIT;
         let result = self.reader_before(now, deadline);
         #[cfg(test)]
         crate::storage_retention::test_hook(&self.root, "cg-timing:view-reader-return");
@@ -991,9 +1049,24 @@ impl CallgraphView {
         // deadline; queued readers must not get a fresh window after the lock.
         #[cfg(test)]
         crate::storage_retention::test_hook(&self.root, "cg-timing:query-lock-begin");
+        #[cfg(test)]
+        let query_started = std::time::Instant::now();
         let retry = self.query.try_lock_until(deadline);
         #[cfg(test)]
+        record_read_wait(ReadWaitObservation {
+            stage: ReadWaitStage::QueryLock,
+            started: query_started,
+            deadline,
+            requested: deadline.saturating_duration_since(query_started),
+            finished: std::time::Instant::now(),
+            timed_out: retry.is_none(),
+        });
+        #[cfg(test)]
         crate::storage_retention::test_hook(&self.root, "cg-timing:query-lock-return");
+        #[cfg(test)]
+        if retry.is_none() {
+            crate::storage_retention::test_hook(&self.root, "cg-timing:query-lock-timeout");
+        }
         let mut retry = retry.ok_or_else(graph_building)?;
         let mut steady = self
             .steady
@@ -1172,7 +1245,8 @@ impl CallgraphView {
                 .fetch_add(1, std::sync::atomic::Ordering::Relaxed);
             *acquisition = Some(rx);
         }
-        let remaining = deadline.saturating_duration_since(std::time::Instant::now());
+        let receive_started = std::time::Instant::now();
+        let remaining = deadline.saturating_duration_since(receive_started);
         #[cfg(test)]
         crate::storage_retention::test_hook(
             &self.root,
@@ -1183,6 +1257,15 @@ impl CallgraphView {
         );
         let received = acquisition.as_ref().unwrap().recv_timeout(remaining);
         #[cfg(test)]
+        record_read_wait(ReadWaitObservation {
+            stage: ReadWaitStage::Acquisition,
+            started: receive_started,
+            deadline,
+            requested: remaining,
+            finished: std::time::Instant::now(),
+            timed_out: matches!(&received, Err(crossbeam_channel::RecvTimeoutError::Timeout)),
+        });
+        #[cfg(test)]
         crate::storage_retention::test_hook(
             &self.root,
             match &received {

From 68e0ede44155b0c2f7f4d9daadcdef75d77d2cb5 Mon Sep 17 00:00:00 2001
From: ualtinok <94532+ualtinok@users.noreply.github.com>
Date: Tue, 3 Nov 2026 06:24:07 +0100
Subject: [PATCH 7/8] Zoom timing hooks: skip when the test context has no
 cache root

Co-authored-by: alfonso-aft <289616620+alfonso-aft@users.noreply.github.com>
---
 crates/aft/src/commands/zoom.rs | 16 ++++++++--------
 1 file changed, 8 insertions(+), 8 deletions(-)

diff --git a/crates/aft/src/commands/zoom.rs b/crates/aft/src/commands/zoom.rs
index c4b9b6559..d80031018 100644
--- a/crates/aft/src/commands/zoom.rs
+++ b/crates/aft/src/commands/zoom.rs
@@ -1846,17 +1846,17 @@ fn zoom_one_symbol_inner(
 /// counts as that first use and can start the build.
 fn unavailable_callgraph_field(ctx: &AppContext) -> Option<serde_json::Value> {
     use crate::feature_status::{observe_callgraph_query, IndexEffective};
+    // Timing hooks for the read-bound test. Unconfigured test contexts have no
+    // cache root, so the hooks are skipped there instead of panicking.
     #[cfg(test)]
-    crate::storage_retention::test_hook(
-        &ctx.canonical_cache_root(),
-        "cg-timing:zoom-observe-begin",
-    );
+    if let Some(root) = ctx.canonical_cache_root_opt() {
+        crate::storage_retention::test_hook(&root, "cg-timing:zoom-observe-begin");
+    }
     let observation = observe_callgraph_query(ctx);
     #[cfg(test)]
-    crate::storage_retention::test_hook(
-        &ctx.canonical_cache_root(),
-        "cg-timing:zoom-observe-return",
-    );
+    if let Some(root) = ctx.canonical_cache_root_opt() {
+        crate::storage_retention::test_hook(&root, "cg-timing:zoom-observe-return");
+    }
     let code = match observation.effective {
         IndexEffective::Ready => return None,
         IndexEffective::Off => "callgraph_off",

From 05e54d2582bfe7ef697078400467ec92261040ab Mon Sep 17 00:00:00 2001
From: ualtinok <94532+ualtinok@users.noreply.github.com>
Date: Tue, 3 Nov 2026 06:26:59 +0100
Subject: [PATCH 8/8] Call-graph cancel test: generous positive waits for
 acquisition tokens on slow runners

Co-authored-by: alfonso-aft <289616620+alfonso-aft@users.noreply.github.com>
---
 crates/aft/src/views/callgraph.rs | 6 ++++--
 1 file changed, 4 insertions(+), 2 deletions(-)

diff --git a/crates/aft/src/views/callgraph.rs b/crates/aft/src/views/callgraph.rs
index 7641fcc42..a5219b06f 100644
--- a/crates/aft/src/views/callgraph.rs
+++ b/crates/aft/src/views/callgraph.rs
@@ -1893,8 +1893,10 @@ mod tests {
             }),
         );
         drop(graph.ready_reader_for_test());
+        // Positive waits: a loaded Windows runner can take seconds to schedule
+        // an acquisition. Only the cancellation check below is timing-sensitive.
         let old = tokens_rx
-            .recv_timeout(std::time::Duration::from_secs(2))
+            .recv_timeout(std::time::Duration::from_secs(30))
             .unwrap();
         let added = root.join("c.ts");
         std::fs::write(
@@ -1906,7 +1908,7 @@ mod tests {
         let next_graph = graph.clone();
         let next = std::thread::spawn(move || next_graph.reader());
         let current = tokens_rx
-            .recv_timeout(std::time::Duration::from_secs(2))
+            .recv_timeout(std::time::Duration::from_secs(30))
             .unwrap();
         assert_ne!(old.progress_key(), current.progress_key());
         graph.cancel();