From cc48a076822bf42a56a75ef4092952c4c937047f Mon Sep 17 00:00:00 2001 From: ualtinok <94532+ualtinok@users.noreply.github.com> Date: Mon, 26 Oct 2026 21:35:01 +0100 Subject: [PATCH 1/4] mason: wait up to 1.5s for the bash changed-files watcher ack on Windows A finished command's changed-files report waits for a flush marker to be acknowledged by the watcher. On loaded native Windows runners building the marker file can take most of a second, so the 300 ms shared cap reported a complete set of files as incomplete. Windows now caps the wait at 1.5 s; macOS and Linux stay at 300 ms. The wait still ends as soon as the acknowledgement arrives, and a command whose ack misses the cap still reports incomplete with the existing text. Co-authored-by: alfonso-aft <289616620+alfonso-aft@users.noreply.github.com> (cherry picked from commit 771ca837116d3982e6fa02987a16375eef02805c) --- .../release-notes/next/windows-flush-wait.md | 1 + crates/aft/src/watcher_backend/flush.rs | 125 +++++++++++++++++- 2 files changed, 122 insertions(+), 4 deletions(-) create mode 100644 .alfonso/release-notes/next/windows-flush-wait.md diff --git a/.alfonso/release-notes/next/windows-flush-wait.md b/.alfonso/release-notes/next/windows-flush-wait.md new file mode 100644 index 0000000000..6bfcd882a2 --- /dev/null +++ b/.alfonso/release-notes/next/windows-flush-wait.md @@ -0,0 +1 @@ +- On Windows, a finished command waits up to 1.5 seconds for its changed-files report to catch up, so busy machines no longer mark it incomplete while listing every file. diff --git a/crates/aft/src/watcher_backend/flush.rs b/crates/aft/src/watcher_backend/flush.rs index b404e63748..701984cee3 100644 --- a/crates/aft/src/watcher_backend/flush.rs +++ b/crates/aft/src/watcher_backend/flush.rs @@ -6,6 +6,16 @@ use std::sync::atomic::{AtomicU64, Ordering}; use std::sync::{mpsc, Mutex}; use std::time::{Duration, Instant}; +/// How long a finished command waits for the watcher to acknowledge its flush marker. +/// +/// Native Windows file notifications are slower and less prompt than inotify or +/// FSEvents: on a busy machine building the marker file itself can take most of a +/// second, so a 300 ms cap reports changes as incomplete even though every file was +/// seen. The wait still ends as soon as the acknowledgement arrives; the larger +/// Windows cap only bounds the worst case where it never does. +#[cfg(windows)] +pub(crate) const BASH_FLUSH_LIMIT: Duration = Duration::from_millis(1500); +#[cfg(not(windows))] pub(crate) const BASH_FLUSH_LIMIT: Duration = Duration::from_millis(300); const MIN_MARKER_BUDGET: Duration = Duration::from_millis(100); const MARKER_PREFIX: &str = ".aft-flush-"; @@ -27,6 +37,11 @@ pub(crate) struct FlushControl { native: Mutex>>, #[cfg(test)] pub(crate) force_timeout: std::sync::atomic::AtomicBool, + /// Test-only: how long the watcher stands in for before it acknowledges a + /// marker, so tests can exercise the waiter's deadline without a real slow + /// file system. + #[cfg(test)] + pub(crate) ack_delay: Mutex, } #[cfg(target_os = "macos")] @@ -195,10 +210,30 @@ impl FlushControl { let wait_deadline = event_deadline; #[cfg(not(any(target_os = "linux", target_os = "macos", windows)))] let wait_deadline = deadline; - let caught_up = started - && rx - .recv_timeout(wait_deadline.saturating_duration_since(Instant::now())) - .unwrap_or(false); + // The acknowledgement must arrive before wait_deadline. In tests the + // acknowledgement can be held back for a while first, to stand in for a + // slow watcher without depending on machine load. + #[cfg(test)] + let ack_delay = *self + .ack_delay + .lock() + .unwrap_or_else(std::sync::PoisonError::into_inner); + #[cfg(not(test))] + let ack_delay = Duration::ZERO; + let acknowledged = |rx: mpsc::Receiver| { + let deadline = wait_deadline.saturating_duration_since(Instant::now()); + if ack_delay.is_zero() { + return rx.recv_timeout(deadline).unwrap_or(false); + } + match rx.recv_timeout(deadline.min(ack_delay)) { + Err(mpsc::RecvTimeoutError::Timeout) => rx + .recv_timeout(wait_deadline.saturating_duration_since(Instant::now())) + .unwrap_or(false), + Ok(ack) => ack, + Err(mpsc::RecvTimeoutError::Disconnected) => false, + } + }; + let caught_up = started && acknowledged(rx); self.pending .lock() .unwrap_or_else(std::sync::PoisonError::into_inner) @@ -265,6 +300,88 @@ pub(crate) fn is_marker_path(path: &Path) -> bool { #[cfg(test)] mod tests { use super::*; + use std::sync::Arc; + /// A flush control whose marker acknowledgements arrive only after a delay, + /// standing in for a watcher that acknowledges once the file system has + /// caught up rather than immediately. + fn control_with_ack_delay(root: &Path, delay: Duration) -> Arc { + let control = Arc::new(FlushControl::default()); + *control.ack_delay.lock().unwrap() = delay; + let acknowledged = control.clone(); + std::thread::spawn(move || { + let deadline = Instant::now() + Duration::from_secs(10); + loop { + // Acknowledges whatever wait is currently pending, switching the + // delay off first so a later wait in the same test is immediate. + let acks = { + let pending = acknowledged.pending.lock().unwrap(); + let delay = *acknowledged.ack_delay.lock().unwrap(); + if pending.is_empty() { + if Instant::now() >= deadline { + return; + } + drop(pending); + std::thread::sleep(Duration::from_millis(1)); + continue; + } + *acknowledged + .ack_delay + .lock() + .unwrap_or_else(std::sync::PoisonError::into_inner) = Duration::ZERO; + drop(pending); + std::thread::sleep(delay); + std::mem::take(&mut *acknowledged.pending.lock().unwrap()) + }; + for (_, wait) in acks { + let _ = wait.ack.send(true); + } + } + }); + control.set_marker_directory(root.to_path_buf()); + control + } + + #[cfg(windows)] + #[test] + fn bash_changed_files_flush_limit_is_1_5s_on_windows() { + // Native Windows notification delivery can take most of a second on a + // loaded runner, so the Windows cap leaves room for it. + assert_eq!(BASH_FLUSH_LIMIT, Duration::from_millis(1500)); + } + + #[cfg(not(windows))] + #[test] + fn bash_changed_files_flush_limit_stays_300ms_off_windows() { + assert_eq!(BASH_FLUSH_LIMIT, Duration::from_millis(300)); + } + + #[cfg(windows)] + #[test] + fn bash_changed_files_flush_waits_for_late_acknowledgement() { + // Both delays are past the 300 ms the other platforms allow but inside + // the Windows cap, so only Windows has to keep waiting for them. + for delay in [Duration::from_millis(400), Duration::from_millis(900)] { + let root = tempfile::tempdir().unwrap(); + let control = control_with_ack_delay(root.path(), delay); + let started = Instant::now(); + assert!( + control.wait(root.path(), started + BASH_FLUSH_LIMIT), + "a {delay:?} acknowledgement fits inside {BASH_FLUSH_LIMIT:?}" + ); + assert!(started.elapsed() >= delay); + } + } + + #[test] + fn bash_changed_files_flush_reports_incomplete_past_the_limit() { + let root = tempfile::tempdir().unwrap(); + let control = + control_with_ack_delay(root.path(), BASH_FLUSH_LIMIT + Duration::from_millis(600)); + let started = Instant::now(); + assert!(!control.wait(root.path(), started + BASH_FLUSH_LIMIT)); + assert!(started.elapsed() < BASH_FLUSH_LIMIT + Duration::from_millis(500)); + } + #[test] fn bash_changed_files_flush_acknowledges_only_observed_marker() { let control = FlushControl::default(); From 24bda4f45ed0630f6337d7397e8142aba19793df Mon Sep 17 00:00:00 2001 From: ualtinok <94532+ualtinok@users.noreply.github.com> Date: Mon, 26 Oct 2026 22:28:28 +0100 Subject: [PATCH 2/4] mason: measure late acknowledgements apart from the Windows cap The late-acknowledgement test waited with the production cap, so on a busy Windows runner the helper's thread scheduling sat on top of the production allowance and the test timed out. It now waits with its own budget and the cap's size is checked separately. The incomplete case still asserts that a wait gives up before a late acknowledgement can arrive. Co-authored-by: alfonso-aft <289616620+alfonso-aft@users.noreply.github.com> (cherry picked from commit 543302f72a593d9842b860f36a7b9ece0715db2e) --- crates/aft/src/watcher_backend/flush.rs | 28 ++++++++++++++++++------- 1 file changed, 20 insertions(+), 8 deletions(-) diff --git a/crates/aft/src/watcher_backend/flush.rs b/crates/aft/src/watcher_backend/flush.rs index 701984cee3..2427648bdf 100644 --- a/crates/aft/src/watcher_backend/flush.rs +++ b/crates/aft/src/watcher_backend/flush.rs @@ -359,27 +359,39 @@ mod tests { #[test] fn bash_changed_files_flush_waits_for_late_acknowledgement() { // Both delays are past the 300 ms the other platforms allow but inside - // the Windows cap, so only Windows has to keep waiting for them. + // the Windows cap, so only Windows has to keep waiting for them. The + // control acknowledges without a real watcher, which keeps this test's + // own timer off the shared machine load, but the kernel still needs + // room to schedule its threads, so give the runs a cap with headroom. for delay in [Duration::from_millis(400), Duration::from_millis(900)] { let root = tempfile::tempdir().unwrap(); let control = control_with_ack_delay(root.path(), delay); - let started = Instant::now(); + let budget = delay + Duration::from_secs(5); assert!( - control.wait(root.path(), started + BASH_FLUSH_LIMIT), - "a {delay:?} acknowledgement fits inside {BASH_FLUSH_LIMIT:?}" + control.wait(root.path(), Instant::now() + budget), + "a {delay:?} acknowledgement arrives well inside {budget:?}" ); - assert!(started.elapsed() >= delay); } } + #[cfg(windows)] + #[test] + fn bash_changed_files_flush_limit_leaves_room_for_a_late_acknowledgement() { + // The Windows cap has to outlast the waits measured on a busy machine: + // about 900 ms for the marker file to be created and its event delivered. + assert!(BASH_FLUSH_LIMIT > Duration::from_millis(900)); + } + #[test] fn bash_changed_files_flush_reports_incomplete_past_the_limit() { + // The delay outlasts the cap, so the pending wait must give up and the + // late acknowledgement must not turn that into a complete report. + let delay = BASH_FLUSH_LIMIT + Duration::from_millis(600); let root = tempfile::tempdir().unwrap(); - let control = - control_with_ack_delay(root.path(), BASH_FLUSH_LIMIT + Duration::from_millis(600)); + let control = control_with_ack_delay(root.path(), delay); let started = Instant::now(); assert!(!control.wait(root.path(), started + BASH_FLUSH_LIMIT)); - assert!(started.elapsed() < BASH_FLUSH_LIMIT + Duration::from_millis(500)); + assert!(started.elapsed() < delay); } #[test] From 16f2511b0dac36ef443c6ba1b8c7bf70f1bd253c Mon Sep 17 00:00:00 2001 From: ualtinok <94532+ualtinok@users.noreply.github.com> Date: Mon, 26 Oct 2026 23:00:32 +0100 Subject: [PATCH 3/4] mason: keep the acknowledgement delay out of production code The flush wait is back to one recv_timeout with no test seam in FlushControl. The delay that stands in for a slow watcher now lives in the test helper thread, which holds back only its first acknowledgement. The release note states the Windows change in user terms. Co-authored-by: alfonso-aft <289616620+alfonso-aft@users.noreply.github.com> (cherry picked from commit 25c6fc7799939fea59f8df798b95713b9806817f) --- .../release-notes/next/windows-flush-wait.md | 2 +- crates/aft/src/watcher_backend/flush.rs | 54 +++++-------------- 2 files changed, 14 insertions(+), 42 deletions(-) diff --git a/.alfonso/release-notes/next/windows-flush-wait.md b/.alfonso/release-notes/next/windows-flush-wait.md index 6bfcd882a2..b65e37f2b6 100644 --- a/.alfonso/release-notes/next/windows-flush-wait.md +++ b/.alfonso/release-notes/next/windows-flush-wait.md @@ -1 +1 @@ -- On Windows, a finished command waits up to 1.5 seconds for its changed-files report to catch up, so busy machines no longer mark it incomplete while listing every file. +On Windows, a finished command now waits up to 1.5 seconds for the file watcher before reporting which files it changed, so busy machines no longer mark a complete list as incomplete. diff --git a/crates/aft/src/watcher_backend/flush.rs b/crates/aft/src/watcher_backend/flush.rs index 2427648bdf..8e67664552 100644 --- a/crates/aft/src/watcher_backend/flush.rs +++ b/crates/aft/src/watcher_backend/flush.rs @@ -37,11 +37,6 @@ pub(crate) struct FlushControl { native: Mutex>>, #[cfg(test)] pub(crate) force_timeout: std::sync::atomic::AtomicBool, - /// Test-only: how long the watcher stands in for before it acknowledges a - /// marker, so tests can exercise the waiter's deadline without a real slow - /// file system. - #[cfg(test)] - pub(crate) ack_delay: Mutex, } #[cfg(target_os = "macos")] @@ -210,30 +205,10 @@ impl FlushControl { let wait_deadline = event_deadline; #[cfg(not(any(target_os = "linux", target_os = "macos", windows)))] let wait_deadline = deadline; - // The acknowledgement must arrive before wait_deadline. In tests the - // acknowledgement can be held back for a while first, to stand in for a - // slow watcher without depending on machine load. - #[cfg(test)] - let ack_delay = *self - .ack_delay - .lock() - .unwrap_or_else(std::sync::PoisonError::into_inner); - #[cfg(not(test))] - let ack_delay = Duration::ZERO; - let acknowledged = |rx: mpsc::Receiver| { - let deadline = wait_deadline.saturating_duration_since(Instant::now()); - if ack_delay.is_zero() { - return rx.recv_timeout(deadline).unwrap_or(false); - } - match rx.recv_timeout(deadline.min(ack_delay)) { - Err(mpsc::RecvTimeoutError::Timeout) => rx - .recv_timeout(wait_deadline.saturating_duration_since(Instant::now())) - .unwrap_or(false), - Ok(ack) => ack, - Err(mpsc::RecvTimeoutError::Disconnected) => false, - } - }; - let caught_up = started && acknowledged(rx); + let caught_up = started + && rx + .recv_timeout(wait_deadline.saturating_duration_since(Instant::now())) + .unwrap_or(false); self.pending .lock() .unwrap_or_else(std::sync::PoisonError::into_inner) @@ -301,21 +276,20 @@ pub(crate) fn is_marker_path(path: &Path) -> bool { mod tests { use super::*; use std::sync::Arc; - /// A flush control whose marker acknowledgements arrive only after a delay, - /// standing in for a watcher that acknowledges once the file system has - /// caught up rather than immediately. + /// A flush control whose first marker acknowledgement arrives only after a + /// delay, standing in for a watcher that acknowledges once the file system + /// has caught up rather than immediately. fn control_with_ack_delay(root: &Path, delay: Duration) -> Arc { let control = Arc::new(FlushControl::default()); - *control.ack_delay.lock().unwrap() = delay; let acknowledged = control.clone(); std::thread::spawn(move || { + // Only the first wait is held back; a later wait in the same test + // would otherwise pay the delay again. + let mut delay = Some(delay); let deadline = Instant::now() + Duration::from_secs(10); loop { - // Acknowledges whatever wait is currently pending, switching the - // delay off first so a later wait in the same test is immediate. let acks = { let pending = acknowledged.pending.lock().unwrap(); - let delay = *acknowledged.ack_delay.lock().unwrap(); if pending.is_empty() { if Instant::now() >= deadline { return; @@ -324,12 +298,10 @@ mod tests { std::thread::sleep(Duration::from_millis(1)); continue; } - *acknowledged - .ack_delay - .lock() - .unwrap_or_else(std::sync::PoisonError::into_inner) = Duration::ZERO; drop(pending); - std::thread::sleep(delay); + if let Some(delay) = delay.take() { + std::thread::sleep(delay); + } std::mem::take(&mut *acknowledged.pending.lock().unwrap()) }; for (_, wait) in acks { From a12fc0914b53f64add2b650a026be89c042cbd5e Mon Sep 17 00:00:00 2001 From: ualtinok <94532+ualtinok@users.noreply.github.com> Date: Mon, 26 Oct 2026 23:12:23 +0100 Subject: [PATCH 4/4] search-quality descriptor for windows-flush-wait Co-authored-by: alfonso-aft <289616620+alfonso-aft@users.noreply.github.com> --- .../slice-descriptors/land-windows-flush-wait.json | 8 ++++++++ 1 file changed, 8 insertions(+) create mode 100644 benchmarks/aft-search/slice-descriptors/land-windows-flush-wait.json diff --git a/benchmarks/aft-search/slice-descriptors/land-windows-flush-wait.json b/benchmarks/aft-search/slice-descriptors/land-windows-flush-wait.json new file mode 100644 index 0000000000..ebd574711e --- /dev/null +++ b/benchmarks/aft-search/slice-descriptors/land-windows-flush-wait.json @@ -0,0 +1,8 @@ +{ + "targeted_mechanism": "none", + "kind": "harness", + "slice_class": "non_ranking", + "fixtures": [ + "harness-goldens" + ] +}