Skip to content

Commit e5da196

Browse files
Merge pull request #252 from ScriptedAlchemy/fix/flaky-tests
test: de-flake intermittent CI tests (parallel-load resilience)
2 parents 237ee50 + d5280bf commit e5da196

6 files changed

Lines changed: 244 additions & 55 deletions

File tree

src/mcp/hook_events.rs

Lines changed: 59 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -276,12 +276,66 @@ mod tests {
276276
}
277277
}
278278

279+
/// Resolves the `git` executable to an absolute path exactly once per
280+
/// process. Under heavy parallel test load (nextest spawns one process per
281+
/// test, each spawning several `git` subprocesses), a bare
282+
/// `Command::new("git")` PATH lookup can transiently fail the spawn with
283+
/// `ENOENT` ("No such file or directory") even though git is installed.
284+
/// Resolving to an absolute path up front, plus a `GIT` env override,
285+
/// removes the per-spawn PATH walk and makes the lookup deterministic.
286+
fn git_program() -> std::ffi::OsString {
287+
use std::sync::OnceLock;
288+
static GIT: OnceLock<std::ffi::OsString> = OnceLock::new();
289+
GIT.get_or_init(|| {
290+
if let Some(explicit) = std::env::var_os("GIT") {
291+
return explicit;
292+
}
293+
let exe_name = if cfg!(windows) { "git.exe" } else { "git" };
294+
if let Some(paths) = std::env::var_os("PATH") {
295+
for dir in std::env::split_paths(&paths) {
296+
let candidate = dir.join(exe_name);
297+
if candidate.is_file() {
298+
return candidate.into_os_string();
299+
}
300+
}
301+
}
302+
// Fall back to a bare name and let the OS resolve it.
303+
std::ffi::OsString::from("git")
304+
})
305+
.clone()
306+
}
307+
279308
fn run_git(cwd: &Path, args: &[&str]) {
280-
let output = Command::new("git")
281-
.args(args)
282-
.current_dir(cwd)
283-
.output()
284-
.unwrap_or_else(|e| panic!("git {args:?} should run: {e}"));
309+
// A cwd that does not yet exist makes the spawn itself fail with
310+
// ENOENT, which is indistinguishable from git-not-found; guard it so
311+
// any real failure is attributable.
312+
assert!(
313+
cwd.is_dir(),
314+
"git cwd {cwd:?} should exist before running git {args:?}"
315+
);
316+
let git = git_program();
317+
// Retry a transient spawn ENOENT a few times: under load the initial
318+
// fork/exec can spuriously fail even with a valid absolute program.
319+
let mut last_err: Option<std::io::Error> = None;
320+
let mut output = None;
321+
for attempt in 0..5 {
322+
match Command::new(&git).args(args).current_dir(cwd).output() {
323+
Ok(out) => {
324+
output = Some(out);
325+
break;
326+
}
327+
Err(e) if e.kind() == std::io::ErrorKind::NotFound && attempt < 4 => {
328+
last_err = Some(e);
329+
std::thread::sleep(std::time::Duration::from_millis(20 * (attempt + 1)));
330+
}
331+
Err(e) => {
332+
panic!("git {args:?} should run (program {git:?}): {e}");
333+
}
334+
}
335+
}
336+
let output = output.unwrap_or_else(|| {
337+
panic!("git {args:?} should run (program {git:?}) after retries: {last_err:?}")
338+
});
285339
assert!(
286340
output.status.success(),
287341
"git {:?} failed\nstdout:\n{}\nstderr:\n{}",

tests/automation_runner_test/backend.rs

Lines changed: 8 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -24,12 +24,15 @@ use crate::common::{
2424

2525
static ENV_LOCK: Mutex<()> = Mutex::new(());
2626

27+
/// Success-path budget for the fake codex app-server child to spawn (a real
28+
/// python interpreter) and complete its scripted turn. This is the upper bound
29+
/// the backend waits before declaring a timeout; it must be generous enough
30+
/// that a slow python spawn/schedule under nextest's process-per-test
31+
/// parallelism can never false-fire it, while still failing fast on a genuine
32+
/// hang. Tests that deliberately exercise the timeout path pass their own tight
33+
/// `Duration` (e.g. 300ms) and are unaffected by this value.
2734
fn fake_codex_response_timeout() -> Duration {
28-
if cfg!(windows) {
29-
Duration::from_secs(30)
30-
} else {
31-
Duration::from_secs(5)
32-
}
35+
Duration::from_secs(30)
3336
}
3437

3538
fn fake_codex_response_timeout_secs() -> u64 {

tests/common/mod.rs

Lines changed: 85 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -389,6 +389,35 @@ pub fn tracedecay_command_with_home(home: &Path) -> Command {
389389
command
390390
}
391391

392+
/// Resolves the `git` executable to an absolute path exactly once per process.
393+
///
394+
/// Under heavy parallel test load (nextest spawns one process per test, each
395+
/// spawning several `git` subprocesses), a bare `Command::new("git")` PATH
396+
/// lookup can transiently fail the spawn with `ENOENT` ("No such file or
397+
/// directory") even though git is installed. Resolving to an absolute path up
398+
/// front — with an optional `GIT` env override — removes the per-spawn PATH
399+
/// walk and makes the lookup deterministic.
400+
pub fn git_program() -> std::ffi::OsString {
401+
use std::sync::OnceLock;
402+
static GIT: OnceLock<std::ffi::OsString> = OnceLock::new();
403+
GIT.get_or_init(|| {
404+
if let Some(explicit) = std::env::var_os("GIT") {
405+
return explicit;
406+
}
407+
let exe_name = if cfg!(windows) { "git.exe" } else { "git" };
408+
if let Some(paths) = std::env::var_os("PATH") {
409+
for dir in std::env::split_paths(&paths) {
410+
let candidate = dir.join(exe_name);
411+
if candidate.is_file() {
412+
return candidate.into_os_string();
413+
}
414+
}
415+
}
416+
std::ffi::OsString::from("git")
417+
})
418+
.clone()
419+
}
420+
392421
#[cfg(unix)]
393422
pub fn daemon_socket_path(home: &Path) -> PathBuf {
394423
canonical_existing_path(home).join(".tracedecay/daemon.sock")
@@ -438,19 +467,68 @@ pub fn response_to_json(mut response: ureq::http::Response<ureq::Body>) -> (u16,
438467
(status, parsed)
439468
}
440469

470+
/// True when a `ureq` error is a connection-level failure that a freshly
471+
/// started (or briefly overloaded) server can transiently raise before it is
472+
/// steadily accepting requests: peer disconnected, connection refused/reset,
473+
/// or a bare I/O error. These are safe to retry for idempotent test requests;
474+
/// an HTTP status error is NOT one of these (the agent is built with
475+
/// `http_status_as_error(false)`, so 4xx/5xx come back as `Ok`).
476+
pub fn is_transient_connection_error(err: &ureq::Error) -> bool {
477+
match err {
478+
ureq::Error::ConnectionFailed => true,
479+
ureq::Error::Io(_) => true,
480+
other => {
481+
// Fall back to a message match so newer/renamed variants (e.g.
482+
// "Peer disconnected", "connection reset") still count as transient
483+
// without pinning to a specific ureq version's enum shape.
484+
let text = other.to_string().to_ascii_lowercase();
485+
text.contains("peer disconnected")
486+
|| text.contains("connection refused")
487+
|| text.contains("connection reset")
488+
|| text.contains("broken pipe")
489+
|| text.contains("timed out")
490+
}
491+
}
492+
}
493+
494+
/// Issues an idempotent HTTP request, retrying transient connection-level
495+
/// errors (the server racing its own readiness under parallel load) with a
496+
/// short bounded backoff. `send` performs one attempt; a `ureq::Error` that
497+
/// passes [`is_transient_connection_error`] is retried, any other error (or
498+
/// exhausted retries) panics with `label`.
499+
pub fn http_call_with_retry(
500+
label: &str,
501+
send: impl Fn() -> Result<ureq::http::Response<ureq::Body>, ureq::Error>,
502+
) -> ureq::http::Response<ureq::Body> {
503+
let mut last_err: Option<ureq::Error> = None;
504+
for attempt in 0..12 {
505+
match send() {
506+
Ok(response) => return response,
507+
Err(err) if is_transient_connection_error(&err) => {
508+
last_err = Some(err);
509+
std::thread::sleep(Duration::from_millis(25 * (attempt + 1)));
510+
}
511+
Err(err) => panic!("{label} failed: {err}"),
512+
}
513+
}
514+
panic!("{label} failed after retries: {last_err:?}");
515+
}
516+
441517
pub fn get_json(agent: &ureq::Agent, url: &str) -> (u16, Value) {
442-
let response = match agent.get(url).call() {
443-
Ok(response) => response,
444-
Err(err) => panic!("GET {url} failed: {err}"),
445-
};
518+
let response = http_call_with_retry(&format!("GET {url}"), || agent.get(url).call());
446519
response_to_json(response)
447520
}
448521

449522
pub async fn wait_for_dashboard(agent: &ureq::Agent, base_url: &str) {
450523
let probe = format!("{base_url}/api/capabilities");
451-
for _ in 0..80 {
452-
if agent.get(&probe).call().is_ok() {
453-
return;
524+
// Poll until the server both accepts the connection AND returns a real
525+
// HTTP response (2xx). A bare connect success is not enough — the server
526+
// can accept then drop the socket during startup ("Peer disconnected").
527+
for _ in 0..160 {
528+
if let Ok(response) = agent.get(&probe).call() {
529+
if response.status().is_success() {
530+
return;
531+
}
454532
}
455533
tokio::time::sleep(Duration::from_millis(50)).await;
456534
}

tests/core_cli_suite/tool_daemon_test.rs

Lines changed: 47 additions & 15 deletions
Original file line numberDiff line numberDiff line change
@@ -16,6 +16,20 @@ use tracedecay::storage::{
1616
default_profile_project_id, write_enrollment_marker, EnrollmentMarker, StorageMode,
1717
};
1818

19+
/// Bound for waits that depend on spawning and running the real `tracedecay`
20+
/// CLI as a child process: connecting to the fake daemon socket and forwarding
21+
/// the observed request back to the test thread. Under nextest's
22+
/// process-per-test parallelism the fork/exec + init of that child can be
23+
/// scheduled slowly on a loaded runner, so a 2s bound false-fires. This is a
24+
/// generous ceiling that still fails fast on a genuine hang (the CLI normally
25+
/// connects in well under a second).
26+
const CLI_ROUNDTRIP_TIMEOUT: Duration = Duration::from_secs(20);
27+
28+
/// Bound for local, in-process readiness signals (a spawned thread binding a
29+
/// socket and sending on an mpsc channel). These do not spawn external
30+
/// processes, but the thread can still be scheduled slowly under load.
31+
const LOCAL_READY_TIMEOUT: Duration = Duration::from_secs(10);
32+
1933
fn init_project_with_cli(home: &Path, project: &Path) {
2034
std::fs::create_dir_all(project.join("src")).unwrap();
2135
std::fs::write(
@@ -41,11 +55,29 @@ fn init_project_with_cli(home: &Path, project: &Path) {
4155
}
4256

4357
fn git(project: &Path, args: &[&str]) {
44-
let output = std::process::Command::new("git")
45-
.args(args)
46-
.current_dir(project)
47-
.output()
48-
.expect("git should run");
58+
let git = crate::common::git_program();
59+
// Retry a transient spawn ENOENT under heavy parallel load.
60+
let mut last_err: Option<std::io::Error> = None;
61+
let mut output = None;
62+
for attempt in 0..5 {
63+
match std::process::Command::new(&git)
64+
.args(args)
65+
.current_dir(project)
66+
.output()
67+
{
68+
Ok(out) => {
69+
output = Some(out);
70+
break;
71+
}
72+
Err(e) if e.kind() == std::io::ErrorKind::NotFound && attempt < 4 => {
73+
last_err = Some(e);
74+
std::thread::sleep(Duration::from_millis(20 * (attempt + 1)));
75+
}
76+
Err(e) => panic!("git {args:?} should run (program {git:?}): {e}"),
77+
}
78+
}
79+
let output =
80+
output.unwrap_or_else(|| panic!("git {args:?} should run after retries: {last_err:?}"));
4981
assert!(
5082
output.status.success(),
5183
"git {:?} failed\nstdout:\n{}\nstderr:\n{}",
@@ -154,7 +186,7 @@ fn spawn_sentinel_daemon_with_notification(
154186
.expect("set listener nonblocking");
155187
ready_tx.send(()).expect("notify fake daemon readiness");
156188

157-
let deadline = Instant::now() + Duration::from_secs(2);
189+
let deadline = Instant::now() + CLI_ROUNDTRIP_TIMEOUT;
158190
let (stream, _) = loop {
159191
match listener.accept() {
160192
Ok(accepted) => break accepted,
@@ -171,7 +203,7 @@ fn spawn_sentinel_daemon_with_notification(
171203
.set_nonblocking(false)
172204
.expect("set accepted stream blocking");
173205
stream
174-
.set_write_timeout(Some(Duration::from_secs(2)))
206+
.set_write_timeout(Some(CLI_ROUNDTRIP_TIMEOUT))
175207
.expect("write timeout");
176208

177209
let mut reader = BufReader::new(stream.try_clone().expect("clone fake daemon stream"));
@@ -228,7 +260,7 @@ fn spawn_sentinel_daemon_with_notification(
228260
});
229261

230262
ready_rx
231-
.recv_timeout(Duration::from_secs(2))
263+
.recv_timeout(LOCAL_READY_TIMEOUT)
232264
.expect("fake daemon should become ready");
233265
request_rx
234266
}
@@ -245,7 +277,7 @@ fn spawn_hook_event_daemon(socket_path: PathBuf) -> mpsc::Receiver<Value> {
245277
.expect("set listener nonblocking");
246278
ready_tx.send(()).expect("notify fake daemon readiness");
247279

248-
let deadline = Instant::now() + Duration::from_secs(2);
280+
let deadline = Instant::now() + CLI_ROUNDTRIP_TIMEOUT;
249281
let (stream, _) = loop {
250282
match listener.accept() {
251283
Ok(accepted) => break accepted,
@@ -292,7 +324,7 @@ fn spawn_hook_event_daemon(socket_path: PathBuf) -> mpsc::Receiver<Value> {
292324
});
293325

294326
ready_rx
295-
.recv_timeout(Duration::from_secs(2))
327+
.recv_timeout(LOCAL_READY_TIMEOUT)
296328
.expect("fake daemon should become ready");
297329
request_rx
298330
}
@@ -342,7 +374,7 @@ fn assert_hook_notification(
342374
);
343375

344376
let request = observed_request
345-
.recv_timeout(Duration::from_secs(2))
377+
.recv_timeout(CLI_ROUNDTRIP_TIMEOUT)
346378
.expect("fake daemon should receive hook event");
347379
assert_eq!(request["params"]["agent"], expected_agent);
348380
assert_eq!(request["params"]["event"], expected_event);
@@ -592,7 +624,7 @@ fn tool_cli_invokes_mcp_tool_through_daemon_socket() {
592624
"tool CLI should print daemon response, got:\n{stdout}"
593625
);
594626
observed_request
595-
.recv_timeout(Duration::from_secs(2))
627+
.recv_timeout(CLI_ROUNDTRIP_TIMEOUT)
596628
.expect("fake daemon should receive tools/call request");
597629
}
598630

@@ -635,7 +667,7 @@ fn tool_cli_skips_daemon_notifications_until_matching_response() {
635667
"tool CLI should print daemon response after notification, got:\n{stdout}"
636668
);
637669
observed_request
638-
.recv_timeout(Duration::from_secs(2))
670+
.recv_timeout(CLI_ROUNDTRIP_TIMEOUT)
639671
.expect("fake daemon should receive tools/call request");
640672
}
641673

@@ -690,7 +722,7 @@ fn profile_scoped_tool_cli_invokes_daemon_without_project_handshake() {
690722
"tool CLI should print daemon response, got:\n{stdout}"
691723
);
692724
let request = observed_request
693-
.recv_timeout(Duration::from_secs(2))
725+
.recv_timeout(CLI_ROUNDTRIP_TIMEOUT)
694726
.expect("fake daemon should receive profile-scoped tools/call request");
695727
assert_eq!(
696728
request["params"]["arguments"]["storage_scope"],
@@ -786,7 +818,7 @@ fn first_touch_store_tool_cli_invokes_daemon_with_init_permission() {
786818
"tool CLI should print daemon response, got:\n{stdout}"
787819
);
788820
let request = observed_request
789-
.recv_timeout(Duration::from_secs(2))
821+
.recv_timeout(CLI_ROUNDTRIP_TIMEOUT)
790822
.expect("fake daemon should receive first-touch tools/call request");
791823
assert_eq!(request["params"]["arguments"]["action"], "add");
792824
}

0 commit comments

Comments
 (0)