diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md index 8f8366a7b9a..1f46169afed 100644 --- a/CONTRIBUTING.md +++ b/CONTRIBUTING.md @@ -72,7 +72,7 @@ tests/fm-send-codex-secondmate-submit-retry.test.sh # fm-send delayed final Ente tests/fm-send-secondmate-marker.test.sh # fm-send from-firstmate marker for kind=secondmate targets: marked vs crewmate/explicit/--key, and the exact marker byte sequence tests/fm-wake-daemon-lifecycle-e2e.test.sh # watcher + daemon lifecycle e2e: restart catch-up, batching, dedupe, stale-pane routing, and digest injection tests/fm-composer-ghost.test.sh # dim-ghost stripping, ghost-only composer detection, and escape-free peek tests -tests/fm-afk-inject-e2e.test.sh # private-socket end-to-end test of the afk injection path (partial-input deferral, swallowed-Enter retry) +tests/fm-afk-inject-e2e.test.sh # event-driven private-socket e2e for afk injection: partial-input deferral, swallowed-Enter retry, and single clean digest tests/fm-bootstrap.test.sh # bootstrap dependency, feature-probe, and crew-dispatch reporting tests tests/fm-no-mistakes-pr-target-guard.test.sh # captain-fork no-mistakes PR target guard for origin, push URLs, gate remotes, and status output tests/fm-grok-harness.test.sh # grok adapter spawn hook, token guard, teardown cleanup, and session-lock detection tests diff --git a/tests/fm-afk-inject-e2e.test.sh b/tests/fm-afk-inject-e2e.test.sh index 3f9791735af..d92d398ff45 100755 --- a/tests/fm-afk-inject-e2e.test.sh +++ b/tests/fm-afk-inject-e2e.test.sh @@ -22,6 +22,10 @@ # # Assert on submitted CONTENT (logged verbatim by the supervisor pane), not pane # appearance — terminal line-wrapping looks like newlines but isn't. +# +# The scenario waits are bounded and event-driven: each poll checks the specific +# daemon/log condition under test, fails quickly if the daemon exits, and prints +# the relevant submitted-log and daemon-state diagnostics on timeout. set -u ROOT="$(cd "$(dirname "${BASH_SOURCE[0]}")/.." && pwd)" @@ -204,6 +208,100 @@ reset_state() { : > "$LOG_FILE" } +dump_wait_diagnostics() { + local desc=$1 + echo "timed out waiting for: $desc" >&2 + echo "submitted log:" >&2 + sed 's/^/ /' "$LOG_FILE" >&2 + echo "daemon log tail:" >&2 + tail -40 "$STATE_DIR/.supervise-daemon.log" 2>/dev/null | sed 's/^/ /' >&2 || true + echo "daemon state:" >&2 + { + printf ' pid_alive=%s\n' "$(kill -0 "${DAEMON_PID:-0}" 2>/dev/null && echo yes || echo no)" + printf ' buffer_bytes=%s\n' "$(wc -c < "$STATE_DIR/.subsuper-escalations" 2>/dev/null || echo 0)" + printf ' swallow_enter=%s\n' "$([ -e "$STATE_DIR/.swallow-enter" ] && echo present || echo absent)" + } >&2 +} + +# Wait until a condition becomes true. The tick count is a hard timeout, not a +# fixed delay after the event has already happened. +wait_for_event() { + local desc=$1 ticks=$2 i=0 + shift 2 + while [ "$i" -lt "$ticks" ]; do + "$@" && return 0 + if [ -n "${DAEMON_PID:-}" ] && ! kill -0 "$DAEMON_PID" 2>/dev/null; then + dump_wait_diagnostics "$desc" + fail "daemon exited while waiting for $desc" + fi + sleep 0.1 + i=$((i + 1)) + done + dump_wait_diagnostics "$desc" + fail "timed out waiting for $desc" +} + +# Wait until a condition becomes true and then remains true long enough to prove +# the daemon did not add a duplicate or leave an escalation buffered. +wait_for_stable_event() { + local desc=$1 ticks=$2 stable_ticks=$3 i=0 stable=0 observed=0 + shift 3 + while [ "$i" -lt "$ticks" ] || [ "$observed" -eq 1 ]; do + if "$@"; then + observed=1 + stable=$((stable + 1)) + [ "$stable" -ge "$stable_ticks" ] && return 0 + else + if [ "$observed" -eq 1 ]; then + dump_wait_diagnostics "$desc" + fail "event became unstable while waiting for $desc" + fi + stable=0 + fi + if [ -n "${DAEMON_PID:-}" ] && ! kill -0 "$DAEMON_PID" 2>/dev/null; then + dump_wait_diagnostics "$desc" + fail "daemon exited while waiting for $desc" + fi + sleep 0.1 + if [ "$observed" -eq 0 ]; then + i=$((i + 1)) + fi + done + dump_wait_diagnostics "$desc" + fail "timed out waiting for stable $desc" +} + +digest_count() { + grep -c 'Supervisor escalate' "$LOG_FILE" 2>/dev/null || true +} + +escalation_buffer_empty() { + [ ! -s "$STATE_DIR/.subsuper-escalations" ] +} + +scenario_a_deferred_with_pending_input() { + grep -q 'inject deferred: supervisor pane has pending input' "$STATE_DIR/.supervise-daemon.log" 2>/dev/null || return 1 + [ -s "$STATE_DIR/.subsuper-escalations" ] || return 1 + ! grep -q 'Supervisor escalate' "$LOG_FILE" 2>/dev/null +} + +scenario_a_delivered_after_idle() { + grep -q 'human draft text' "$LOG_FILE" 2>/dev/null || return 1 + grep -q 'Supervisor escalate' "$LOG_FILE" 2>/dev/null || return 1 + escalation_buffer_empty +} + +scenario_b_delivered_once_after_swallowed_enter() { + [ "$(digest_count)" -eq 1 ] || return 1 + [ ! -e "$STATE_DIR/.swallow-enter" ] || return 1 + escalation_buffer_empty +} + +scenario_c_delivered_once() { + [ "$(digest_count)" -eq 1 ] || return 1 + escalation_buffer_empty +} + # --- pane_input_pending environment self-check ------------------------------ # Verify that pane_input_pending (which uses cursor_y + capture-pane) can detect # typed text in this tmux environment. If it can't, the e2e cannot prove the @@ -250,8 +348,9 @@ test_scenario_a() { # real watcher child. echo "done: PR https://example.test/pr/100" > "$STATE_DIR/fake-c1.status" - # Wait for the watcher to detect the change and the daemon to attempt inject. - sleep 6 + # Wait for the watcher to detect the change and the daemon to defer delivery + # while the pane has pending human input. + wait_for_event "Scenario A pending-input defer" 60 scenario_a_deferred_with_pending_input # Assert: the digest was NOT injected while the pane had pending input. if grep -q 'Supervisor escalate' "$LOG_FILE"; then @@ -269,7 +368,7 @@ test_scenario_a() { sleep 0.5 # Wait for the daemon to retry injection (housekeeping tick = 1s). - sleep 6 + wait_for_event "Scenario A digest after idle" 60 scenario_a_delivered_after_idle # Assert: human text was submitted alone (as a user message). grep -q 'human draft text' "$LOG_FILE" \ @@ -321,7 +420,7 @@ test_scenario_b() { # Wait for the daemon to process the escalation and attempt inject (with the # swallowed Enter, the retry path fires). - sleep 8 + wait_for_stable_event "Scenario B one digest after swallowed Enter" 90 12 scenario_b_delivered_once_after_swallowed_enter # Assert: exactly ONE digest in the log (no duplicate, no loss). local digest_count @@ -368,7 +467,7 @@ test_scenario_c() { start_daemon echo "done: PR https://example.test/pr/300" > "$STATE_DIR/fake-c1.status" - sleep 6 + wait_for_stable_event "Scenario C one digest" 70 12 scenario_c_delivered_once # Exactly one digest line in the submitted log (no duplicate, no loss). local digest_count