test(TASK-050): wait on every expected marker before asserting hook counts

Hook processes are fire-and-forget: the binary's exit drain acknowledges
spawns only, so the STARTED writer can land after the terminal one. The
macro-bracketing tests waited only for the terminal marker and then
asserted STARTED's count immediately, flaking on Windows CI and loaded
Linux runners. The bounded wait now covers every expected marker before
the exact-count and absence assertions run; the probe script's scenario K
comment is corrected to state the spawn-ack-only contract it already
waits around.
This commit is contained in:
Dark-Alex-17 committed 2026-09-17 00:33:37 -06:00
1 parent ec66494e8f
commit 611900057c
2 files changed
+18 -11

No files matched your search

+3 -2
View File
@@ -654,8 +654,9 @@ echo "== Scenario K: global_hooks wildcard grammar (exact, <event>.*, *.<name>,
# two hooks named 'mark' and 'other'. Each sub-case runs the same # two hooks named 'mark' and 'other'. Each sub-case runs the same
# `--agent wc-probe --macro probe` recipe in its own config dir with a # `--agent wc-probe --macro probe` recipe in its own config dir with a
# different global_hooks whitelist, then asserts exactly which markers were # different global_hooks whitelist, then asserts exactly which markers were
# admitted. The binary drains pending hooks before exiting, so post-exit # admitted. The binary's exit drain only acknowledges hook SPAWNS — the hook
# waits only absorb filesystem latency. # processes finish on their own after exit — so every expected marker gets
# its own wait_for before any absence check reads the log.
k_run() { k_run() {
# $1 = label, $2 = marker log, $3.. = global_hooks entries (verbatim) # $1 = label, $2 = marker log, $3.. = global_hooks entries (verbatim)
local label="$1" klog="$2" local label="$1" klog="$2"
+15 -9
View File
@@ -130,21 +130,27 @@ fn run_coyote(dir: &Path, args: &[&str]) -> Output {
.unwrap() .unwrap()
} }
/// Bounded poll for the expected terminal marker. The binary drains pending /// Bounded poll until every expected marker is present. The binary's exit
/// hooks before exiting, so the log is normally complete once `output()` /// drain only acknowledges that each hook process SPAWNED — the hooks
/// returns; the poll only absorbs filesystem latency, never paces the run. /// themselves keep running concurrently after `output()` returns, and
/// Marker matching stays byte-exact on both platforms because `lines()` /// nothing orders their writes (the STARTED writer can land after the
/// strips the CRLF that cmd's echo emits on Windows. /// terminal one). Waiting on all expected markers, not just the terminal
fn wait_for_marker(log: &Path, needle: &str) -> String { /// one, keeps the exact-count assertions below race-free. Marker matching
/// stays byte-exact on both platforms because `lines()` strips the CRLF
/// that cmd's echo emits on Windows.
fn wait_for_markers(log: &Path, needles: &[&str]) -> String {
let deadline = Instant::now() + Duration::from_secs(10); let deadline = Instant::now() + Duration::from_secs(10);
loop { loop {
let contents = fs::read_to_string(log).unwrap_or_default(); let contents = fs::read_to_string(log).unwrap_or_default();
if contents.lines().any(|line| line == needle) { if needles
.iter()
.all(|needle| contents.lines().any(|line| line == *needle))
{
return contents; return contents;
} }
assert!( assert!(
Instant::now() < deadline, Instant::now() < deadline,
"timed out waiting for '{needle}'; log so far: {contents:?}" "timed out waiting for {needles:?}; log so far: {contents:?}"
); );
thread::sleep(Duration::from_millis(50)); thread::sleep(Duration::from_millis(50));
} }
@@ -187,7 +193,7 @@ fn probe_macro_run(label: &str, macro_yaml: &str, args: &[&str], expect_success:
} else { } else {
"FAILED" "FAILED"
}; };
let contents = wait_for_marker(&log, terminal); let contents = wait_for_markers(&log, &["STARTED", terminal]);
assert_started_and_single_terminal(&contents, terminal); assert_started_and_single_terminal(&contents, terminal);
contents contents
} }