From 3fa1179e759a85fe128044586833d3597f3d8531 Mon Sep 17 00:00:00 2001 From: fujibee Date: Wed, 26 Aug 2026 09:34:03 +0900 Subject: [PATCH 1/3] test(watch): say what the file held when a delivery wait times out (#1000) The watch liveness case (#67) failed once each on three PRs in one night, on three platforms, and never on main; none of the three logs could say whether the watcher had not delivered or had already exited, because the wait helper reported only "did not appear". On timeout it now prints the file's state -- missing, empty, or its lines -- and, when the caller hands it the watcher's pid, whether that watcher is still running. The #67 site passes its pid. Nothing changes on the green path; the helper still returns 1 on timeout. --- tests/test_watch.bats | 27 +++++++++++++++++++++++++-- 1 file changed, 25 insertions(+), 2 deletions(-) diff --git a/tests/test_watch.bats b/tests/test_watch.bats index 76d6bad74..d15b4e87e 100644 --- a/tests/test_watch.bats +++ b/tests/test_watch.bats @@ -150,12 +150,35 @@ _wait_for_missing() { return 1 } +# Waits up to ten seconds for to appear in . On timeout it says +# what it saw, because a bare failure cannot be classified (#1000): whether +# the file was missing, empty, or holding OTHER lines tells "the watcher never +# delivered" from "it delivered something else", and an optional tells +# "the watcher was still running" from "it had already exited". Three PRs on +# one night each had this fail once on a different platform, and none of the +# three logs could answer either question. _wait_for_file_contains() { - local file="$1" needle="$2" i + local file="$1" needle="$2" pid="${3:-}" i for i in $(seq 1 100); do [ -f "$file" ] && grep -q "$needle" "$file" && return 0 sleep 0.1 done + echo "_wait_for_file_contains: '$needle' did not appear in $file within 10s" >&2 + if [ ! -f "$file" ]; then + echo " file: missing" >&2 + elif [ ! -s "$file" ]; then + echo " file: present, empty" >&2 + else + echo " file: present, $(wc -l < "$file" | tr -d ' ') line(s):" >&2 + sed 's/^/ | /' "$file" >&2 + fi + if [ -n "$pid" ]; then + if kill -0 "$pid" 2>/dev/null; then + echo " watcher $pid: still running" >&2 + else + echo " watcher $pid: exited" >&2 + fi + fi return 1 } @@ -234,7 +257,7 @@ _wait_for_file_contains() { [ -f "$pf" ] bash "$SCRIPTS/send.sh" team bob alice "M1-delivered" >/dev/null - _wait_for_file_contains "$out" "M1-delivered" + _wait_for_file_contains "$out" "M1-delivered" "$w" local first_cursor="$(_read_cursor team alice)" # Owning session dies (reap it so kill -0 reports gone, not a zombie), then a From 877c3d95b3a6918c586964f6be14a48fee638071 Mon Sep 17 00:00:00 2001 From: fujibee Date: Sat, 29 Aug 2026 12:08:50 +0900 Subject: [PATCH 2/3] test(watch): the timeout dump says what it observed, not what it concluded Review found the diagnostic committing the two mistakes it exists to catch. `kill -0` returning false was reported as "watcher exited" -- but kill -0 also fails on EPERM and on an observation error, so that wording claimed absence from a failed presence check (pid 1 is alive and answers false, measured). It now reports "kill -0 could not confirm it running (exited, or not observable)". And `wc -l` counts newlines, not lines, so a partial line mid-write read as nothing; the dump now prints the byte count and whether the last line is unterminated, which tells "wrote nothing" from "a write may be in progress", and closes the stream after an unterminated line so the next diagnostic does not run on. --- tests/test_watch.bats | 20 +++++++++++++++++--- 1 file changed, 17 insertions(+), 3 deletions(-) diff --git a/tests/test_watch.bats b/tests/test_watch.bats index d15b4e87e..a86cf7046 100644 --- a/tests/test_watch.bats +++ b/tests/test_watch.bats @@ -169,14 +169,28 @@ _wait_for_file_contains() { elif [ ! -s "$file" ]; then echo " file: present, empty" >&2 else - echo " file: present, $(wc -l < "$file" | tr -d ' ') line(s):" >&2 + # Bytes and terminator, not `wc -l`: that counts newlines, so a partial + # line the writer had not finished would be invisible -- "0 lines" could + # not tell "wrote nothing" from "mid-write" (review finding). The byte + # count and the last byte answer that. + local bytes terminated="ends with a newline" + bytes="$(wc -c < "$file" | tr -d ' ')" + [ -n "$(tail -c 1 "$file")" ] && terminated="last line is UNTERMINATED (a write may be in progress)" + echo " file: present, $bytes byte(s), $terminated:" >&2 sed 's/^/ | /' "$file" >&2 + # An unterminated final line leaves the stream mid-line; close it so the + # next diagnostic line does not run on. + [ -n "$(tail -c 1 "$file")" ] && echo >&2 fi if [ -n "$pid" ]; then + # `kill -0` failing is NOT proof the process exited: it also fails on + # EPERM and on an observation error. The diagnostic says only what was + # observed (review finding -- the #996 shape: absence claimed from a + # failed presence check). if kill -0 "$pid" 2>/dev/null; then - echo " watcher $pid: still running" >&2 + echo " watcher $pid: running (kill -0 succeeded)" >&2 else - echo " watcher $pid: exited" >&2 + echo " watcher $pid: kill -0 could not confirm it running (exited, or not observable)" >&2 fi fi return 1 From c3ac8cf238b7abfbb5658af2b678e8157e2c8096 Mon Sep 17 00:00:00 2001 From: fujibee Date: Sat, 29 Aug 2026 12:14:59 +0900 Subject: [PATCH 3/3] test(watch): the timeout dump describes one snapshot, not four reads of a live file Review found the dump observing the live file four separate times -- wc -c, a first tail -c 1, sed, a second tail -c 1 -- with a live writer free to append between them, so the byte count, the terminator verdict and the printed content could describe a state that never existed. Everything is computed from a single snapshot copy now, the header says "snapshot at timeout", and a snapshot that cannot be taken is reported as exactly that rather than guessed around. --- tests/test_watch.bats | 40 ++++++++++++++++++++++++++-------------- 1 file changed, 26 insertions(+), 14 deletions(-) diff --git a/tests/test_watch.bats b/tests/test_watch.bats index a86cf7046..b50f830ab 100644 --- a/tests/test_watch.bats +++ b/tests/test_watch.bats @@ -166,21 +166,33 @@ _wait_for_file_contains() { echo "_wait_for_file_contains: '$needle' did not appear in $file within 10s" >&2 if [ ! -f "$file" ]; then echo " file: missing" >&2 - elif [ ! -s "$file" ]; then - echo " file: present, empty" >&2 else - # Bytes and terminator, not `wc -l`: that counts newlines, so a partial - # line the writer had not finished would be invisible -- "0 lines" could - # not tell "wrote nothing" from "mid-write" (review finding). The byte - # count and the last byte answer that. - local bytes terminated="ends with a newline" - bytes="$(wc -c < "$file" | tr -d ' ')" - [ -n "$(tail -c 1 "$file")" ] && terminated="last line is UNTERMINATED (a write may be in progress)" - echo " file: present, $bytes byte(s), $terminated:" >&2 - sed 's/^/ | /' "$file" >&2 - # An unterminated final line leaves the stream mid-line; close it so the - # next diagnostic line does not run on. - [ -n "$(tail -c 1 "$file")" ] && echo >&2 + # ONE observation, reported consistently: the writer is alive, so reading + # the live file once per fact (bytes, terminator, content) can interleave + # with an append and describe a state that never existed (review finding). + # Everything below is computed from a single snapshot copy; the snapshot + # is what the dump describes, and it says so. + local snap bytes terminated="ends with a newline" + snap="$(mktemp "${TMPDIR:-/tmp}/agmsg-wait-dump.XXXXXX")" || snap="" + if [ -z "$snap" ] || ! cp "$file" "$snap" 2>/dev/null; then + echo " file: present, but could not be snapshotted for a consistent dump" >&2 + [ -n "$snap" ] && rm -f "$snap" + elif [ ! -s "$snap" ]; then + echo " file: present, empty (at snapshot time)" >&2 + rm -f "$snap" + else + # Bytes and terminator, not `wc -l`: that counts newlines, so a partial + # line the writer had not finished would be invisible -- "0 lines" + # could not tell "wrote nothing" from "mid-write" (review finding). + bytes="$(wc -c < "$snap" | tr -d ' ')" + [ -n "$(tail -c 1 "$snap")" ] && terminated="last line is UNTERMINATED (a write may be in progress)" + echo " file: snapshot at timeout, $bytes byte(s), $terminated:" >&2 + sed 's/^/ | /' "$snap" >&2 + # An unterminated final line leaves the stream mid-line; close it so + # the next diagnostic line does not run on. + [ -n "$(tail -c 1 "$snap")" ] && echo >&2 + rm -f "$snap" + fi fi if [ -n "$pid" ]; then # `kill -0` failing is NOT proof the process exited: it also fails on