fix: flaky bats tests

Commit `ce52eb7`

Eric Bower · 2026-07-17 15:15:12 -0400 EDT

parent fbf900c

fix: flaky bats tests

5 files changed, +65, -19

M src/main.zig

M src/util.zig

M test/session.bats

M test/stdin_run.bats

M test/test_helper.bash

M src/main.zig

+22, -2

......@@ -2565,6 +2565,12 @@ fn daemonLoop(daemon: *Daemon, server_sock_fd: i32, pty_fd: i32) !void {
    var vt_stream = term.vtStream();
    defer vt_stream.deinit();

    // Carries the tail of the previous PTY read so the task-exit marker
    // search below can see across a read() boundary. Sized to comfortably
    // hold "ZMX_TASK_COMPLETED:" (19 bytes) plus a u8 exit code and CRLF.
    var marker_carry: [32]u8 = undefined;
    var marker_carry_len: usize = 0;

    daemon_loop: while (daemon.running) {
        poll_fds.clearRetainingCapacity();

......@@ -2675,9 +2681,17 @@ fn daemonLoop(daemon: *Daemon, server_sock_fd: i32, pty_fd: i32) !void {
                        util.respondToDeviceAttributes(daemon.alloc, &daemon.pty_write_buf, buf[0..n]);
                    }

                    // In run mode, scan output for exit code marker
                    // In run mode, scan output for exit code marker. The marker
                    // can straddle two PTY reads (more likely under a throttled
                    // scheduler, e.g. containers), so prepend the tail carried
                    // over from the previous read before searching.
                    if (daemon.is_task_mode and daemon.task_exit_code == null) {
                        if (util.findTaskExitMarker(buf[0..n])) |exit_code| {
                        var scan_buf: [marker_carry.len + buf.len]u8 = undefined;
                        @memcpy(scan_buf[0..marker_carry_len], marker_carry[0..marker_carry_len]);
                        @memcpy(scan_buf[marker_carry_len..][0..n], buf[0..n]);
                        const scan_len = marker_carry_len + n;

                        if (util.findTaskExitMarker(scan_buf[0..scan_len])) |exit_code| {
                            daemon.task_exit_code = exit_code;
                            daemon.task_ended_at = @intCast(std.time.timestamp());

......@@ -2689,6 +2703,12 @@ fn daemonLoop(daemon: *Daemon, server_sock_fd: i32, pty_fd: i32) !void {
                                c.has_pending_output = true;
                            }
                        }

                        marker_carry_len = @min(marker_carry.len, scan_len);
                        @memcpy(
                            marker_carry[0..marker_carry_len],
                            scan_buf[scan_len - marker_carry_len .. scan_len],
                        );
                    }

                    // Broadcast data to all clients.

M src/util.zig

+9, -4

......@@ -328,8 +328,14 @@ test "rewritePromptRedraw: embedded in larger output" {
pub fn findTaskExitMarker(output: []const u8) ?u8 {
    const marker = "ZMX_TASK_COMPLETED:";

    // Search for marker in output
    if (std.mem.indexOf(u8, output, marker)) |idx| {
    // The command line is echoed back by the PTY (canonical mode) before the
    // shell evaluates it, so the *first* occurrence of the marker in the
    // output is often the literal, unexpanded "ZMX_TASK_COMPLETED:$?" from
    // the echo, not the real "ZMX_TASK_COMPLETED:<code>" written once the
    // shell actually runs it. Keep scanning past unparseable occurrences
    // instead of giving up on the first one.
    var search_start: usize = 0;
    while (std.mem.indexOfPos(u8, output, search_start, marker)) |idx| {
        const after_marker = output[idx + marker.len ..];

        // Find the exit code number and newline

......@@ -344,8 +350,7 @@ pub fn findTaskExitMarker(output: []const u8) ?u8 {
        if (std.fmt.parseInt(u8, exit_code_str, 10)) |exit_code| {
            return exit_code;
        } else |_| {
            std.log.warn("failed to parse task exit code from: {s}", .{exit_code_str});
            return null;
            search_start = idx + marker.len;
        }
    }

M test/session.bats

+13, -8

...	...		@@ -84,7 +84,7 @@ load test_helper
84	84		@test "send: does not append CR by default" {
85	85		"$ZMX" run test-send-raw -d echo ready
86	86		wait_for_session test-send-raw
87		-	sleep 0.5
	87	+	wait_for_output test-send-raw ready
88	88
89	89		# Send text without \r — it should NOT execute as a command
90	90		run "$ZMX" send test-send-raw "partial-text"

...	...		@@ -107,12 +107,12 @@ load test_helper
107	107		@test "send: accepts piped stdin" {
108	108		"$ZMX" run test-send-pipe -d echo ready
109	109		wait_for_session test-send-pipe
110		-	sleep 0.5
	110	+	wait_for_output test-send-pipe ready
111	111
112	112		run bash -c 'printf "echo piped-marker-xyz789\r" \| "$0" send test-send-pipe' "$ZMX"
113	113		[ "$status" -eq 0 ]
114	114
115		-	sleep 0.5
	115	+	wait_for_output test-send-pipe piped-marker-xyz789
116	116		run "$ZMX" history test-send-pipe
117	117		[[ "$output" == "piped-marker-xyz789" ]]
118	118		}

...	...		@@ -198,7 +198,12 @@ load test_helper
198	198		pid=$("$ZMX" list 2>/dev/null \| grep test-force \| sed 's/.pid=$[0-9]$.*/\1/')
199	199		if [[ -n "$pid" ]]; then
200	200		kill -9 "$pid" 2>/dev/null \|\| true
201		-	sleep 0.5
	201	+	# Wait for the OS to actually reap the process before relying on
	202	+	# --force to see it as dead.
	203	+	for _ in $(seq 1 50); do
	204	+	kill -0 "$pid" 2>/dev/null \|\| break
	205	+	sleep 0.1
	206	+	done
202	207		fi
203	208
204	209		# Regular kill may fail on the dead session; --force cleans up

...	...		@@ -229,7 +234,7 @@ load test_helper
229	234		@test "history: captures session output" {
230	235		"$ZMX" run test-hist -d echo "bats-marker-xyzzy"
231	236		wait_for_session test-hist
232		-	sleep 0.5 # give the command time to produce output
	237	+	wait_for_output test-hist bats-marker-xyzzy
233	238
234	239		run "$ZMX" history test-hist
235	240		[ "$status" -eq 0 ]

...	...		@@ -243,7 +248,7 @@ load test_helper
243	248		@test "wait: returns after session command completes" {
244	249		"$ZMX" run test-wait -d echo done
245	250		wait_for_session test-wait
246		-	sleep 1 # give the command time to finish
	251	+	wait_for_output test-wait done
247	252
248	253		# `wait` should return once the command finishes
249	254		run timeout 10 "$ZMX" wait test-wait

...	...		@@ -274,12 +279,12 @@ load test_helper
274	279		@test "print: text appears in history" {
275	280		"$ZMX" run test-print-hist -d echo ready
276	281		wait_for_session test-print-hist
277		-	sleep 0.3
	282	+	wait_for_output test-print-hist ready
278	283
279	284		# Caller is responsible for newlines; trailing \r\n ensures the text
280	285		# lands on its own line before SIGWINCH triggers a prompt redraw.
281	286		printf "\r\nbats-print-marker-abc123\r\n" \| "$ZMX" print test-print-hist
282		-	sleep 0.3
	287	+	wait_for_output test-print-hist bats-print-marker-abc123
283	288
284	289		run "$ZMX" history test-print-hist
285	290		[ "$status" -eq 0 ]

M test/stdin_run.bats

+5, -5

...	...		@@ -15,7 +15,7 @@ load test_helper
15	15		run bash -c 'printf "echo stdin-marker-abc123\n" \| timeout 10 "$0" run test-stdin-basic' "$ZMX"
16	16		[ "$status" -eq 0 ]
17	17
18		-	sleep 0.3
	18	+	wait_for_output test-stdin-basic stdin-marker-abc123
19	19		run "$ZMX" history test-stdin-basic
20	20		[[ "$output" == "stdin-marker-abc123" ]]
21	21		}

...	...		@@ -24,7 +24,7 @@ load test_helper
24	24		run bash -c 'printf "echo '\''hello \$USER \$(whoami) \\\"double\\\" ; # comment'\''\n" \| timeout 10 "$0" run test-stdin-special' "$ZMX"
25	25		[ "$status" -eq 0 ]
26	26
27		-	sleep 0.3
	27	+	wait_for_output test-stdin-special '$USER'
28	28		run "$ZMX" history test-stdin-special
29	29		[[ "$output" == '$USER' ]]
30	30		[[ "$output" == '$(whoami)' ]]

...	...		@@ -36,7 +36,7 @@ load test_helper
36	36		run bash -c 'printf "%s" "$1" \| timeout 10 "$0" run test-stdin-multi' "$ZMX" "$script"
37	37		[ "$status" -eq 0 ]
38	38
39		-	sleep 0.5
	39	+	wait_for_output test-stdin-multi line-three-ccc
40	40		run "$ZMX" history test-stdin-multi
41	41		[[ "$output" == "line-one-aaa" ]]
42	42		[[ "$output" == "line-two-bbb" ]]

...	...		@@ -51,7 +51,7 @@ load test_helper
51	51		run bash -c 'printf "%s" "$1" \| timeout 10 "$0" run test-stdin-heredoc' "$ZMX" "$script"
52	52		[ "$status" -eq 0 ]
53	53
54		-	sleep 0.5
	54	+	wait_for_output test-stdin-heredoc '$variables that should not expand'
55	55		run "$ZMX" history test-stdin-heredoc
56	56		[[ "$output" == '$variables that should not expand' ]]
57	57		}

...	...		@@ -60,7 +60,7 @@ load test_helper
60	60		run timeout 10 env SHELL=/bin/bash "$ZMX" run test-args-only echo args-only-marker-999
61	61		[ "$status" -eq 0 ]
62	62
63		-	sleep 0.3
	63	+	wait_for_output test-args-only args-only-marker-999
64	64		run "$ZMX" history test-args-only
65	65		[[ "$output" == "args-only-marker-999" ]]
66	66		}

M test/test_helper.bash

+16, -0

......@@ -38,3 +38,19 @@ wait_for_session() {
  echo "Timed out waiting for session '$name'" >&2
  return 1
}

# Helper: wait for a marker to appear in a session's history (up to N seconds).
# Use this instead of a fixed sleep whenever a test needs the daemon to have
# processed and buffered PTY output before it checks/sends more.
wait_for_output() {
  local name="$1" marker="$2" timeout="${3:-5}" i=0
  while (( i < timeout * 10 )); do
    if "$ZMX" history "$name" 2>/dev/null | grep -qF "$marker"; then
      return 0
    fi
    sleep 0.1
    (( i++ )) || true
  done
  echo "Timed out waiting for output '$marker' in session '$name'" >&2
  return 1
}

...	...		@@ -2565,6 +2565,12 @@ fn daemonLoop(daemon: *Daemon, server_sock_fd: i32, pty_fd: i32) !void {
2565	2565		var vt_stream = term.vtStream();
2566	2566		defer vt_stream.deinit();
2567	2567
	2568	+	// Carries the tail of the previous PTY read so the task-exit marker
	2569	+	// search below can see across a read() boundary. Sized to comfortably
	2570	+	// hold "ZMX_TASK_COMPLETED:" (19 bytes) plus a u8 exit code and CRLF.
	2571	+	var marker_carry: [32]u8 = undefined;
	2572	+	var marker_carry_len: usize = 0;
	2573	+
2568	2574		daemon_loop: while (daemon.running) {
2569	2575		poll_fds.clearRetainingCapacity();
2570	2576

...	...		@@ -2689,6 +2703,12 @@ fn daemonLoop(daemon: *Daemon, server_sock_fd: i32, pty_fd: i32) !void {
2689	2703		c.has_pending_output = true;
2690	2704		}
2691	2705		}
	2706	+
	2707	+	marker_carry_len = @min(marker_carry.len, scan_len);
	2708	+	@memcpy(
	2709	+	marker_carry[0..marker_carry_len],
	2710	+	scan_buf[scan_len - marker_carry_len .. scan_len],
	2711	+	);
2692	2712		}
2693	2713
2694	2714		// Broadcast data to all clients.

...	...		@@ -328,8 +328,14 @@ test "rewritePromptRedraw: embedded in larger output" {
328	328		pub fn findTaskExitMarker(output: []const u8) ?u8 {
329	329		const marker = "ZMX_TASK_COMPLETED:";
330	330
331		-	// Search for marker in output
332		-	if (std.mem.indexOf(u8, output, marker)) \|idx\| {
	331	+	// The command line is echoed back by the PTY (canonical mode) before the
	332	+	// shell evaluates it, so the first occurrence of the marker in the
	333	+	// output is often the literal, unexpanded "ZMX_TASK_COMPLETED:$?" from
	334	+	// the echo, not the real "ZMX_TASK_COMPLETED:<code>" written once the
	335	+	// shell actually runs it. Keep scanning past unparseable occurrences
	336	+	// instead of giving up on the first one.
	337	+	var search_start: usize = 0;
	338	+	while (std.mem.indexOfPos(u8, output, search_start, marker)) \|idx\| {
333	339		const after_marker = output[idx + marker.len ..];
334	340
335	341		// Find the exit code number and newline

...	...		@@ -2675,9 +2681,17 @@ fn daemonLoop(daemon: *Daemon, server_sock_fd: i32, pty_fd: i32) !void {
2675	2681		util.respondToDeviceAttributes(daemon.alloc, &daemon.pty_write_buf, buf[0..n]);
2676	2682		}
2677	2683
2678		-	// In run mode, scan output for exit code marker
	2684	+	// In run mode, scan output for exit code marker. The marker
	2685	+	// can straddle two PTY reads (more likely under a throttled
	2686	+	// scheduler, e.g. containers), so prepend the tail carried
	2687	+	// over from the previous read before searching.
2679	2688		if (daemon.is_task_mode and daemon.task_exit_code == null) {
2680		-	if (util.findTaskExitMarker(buf[0..n])) \|exit_code\| {
	2689	+	var scan_buf: [marker_carry.len + buf.len]u8 = undefined;
	2690	+	@memcpy(scan_buf[0..marker_carry_len], marker_carry[0..marker_carry_len]);
	2691	+	@memcpy(scan_buf[marker_carry_len..][0..n], buf[0..n]);
	2692	+	const scan_len = marker_carry_len + n;
	2693	+
	2694	+	if (util.findTaskExitMarker(scan_buf[0..scan_len])) \|exit_code\| {
2681	2695		daemon.task_exit_code = exit_code;
2682	2696		daemon.task_ended_at = @intCast(std.time.timestamp());
2683	2697

...	...		@@ -344,8 +350,7 @@ pub fn findTaskExitMarker(output: []const u8) ?u8 {
344	350		if (std.fmt.parseInt(u8, exit_code_str, 10)) \|exit_code\| {
345	351		return exit_code;
346	352		} else \|_\| {
347		-	std.log.warn("failed to parse task exit code from: {s}", .{exit_code_str});
348		-	return null;
	353	+	search_start = idx + marker.len;
349	354		}
350	355		}
351	356

...	...		@@ -38,3 +38,19 @@ wait_for_session() {
38	38		echo "Timed out waiting for session '$name'" >&2
39	39		return 1
40	40		}
	41	+
	42	+	# Helper: wait for a marker to appear in a session's history (up to N seconds).
	43	+	# Use this instead of a fixed sleep whenever a test needs the daemon to have
	44	+	# processed and buffered PTY output before it checks/sends more.
	45	+	wait_for_output() {
	46	+	local name="$1" marker="$2" timeout="${3:-5}" i=0
	47	+	while (( i < timeout * 10 )); do
	48	+	if "$ZMX" history "$name" 2>/dev/null \| grep -qF "$marker"; then
	49	+	return 0
	50	+	fi
	51	+	sleep 0.1
	52	+	(( i++ )) \|\| true
	53	+	done
	54	+	echo "Timed out waiting for output '$marker' in session '$name'" >&2
	55	+	return 1
	56	+	}

Commit ce52eb7

Commit `ce52eb7`