feat(gates): example apps log to /tmp/<example-app>.log so it can be tailed

Every gate wrote its server output into a per-run mktemp dir that its own
cleanup trap deletes on exit — nothing to follow during the run, nothing
to read after it.

- chat -> /tmp/chat.log, web-app -> /tmp/web-app.log,
  site -> /tmp/site.log, log-watcher -> /tmp/log-watcher.log
- truncated once at gate start, appended for the rest of the run, so one
  file holds the whole run in order
- each gate PRINTS the path as its first line, with the tail -F command
- legs are banner-separated and name their port and env
  (===== leg 2 - port 18902 - env WO_IO=epoll =====)

Appending breaks readiness detection unless it is leg-scoped:

- serve() used to grep the whole file for `listening`, which after the
  switch to append would match an EARLIER leg and return before the new
  server was up. It now records the line count first and searches only
  tail -n "+$LEGFROM"; the ASan scan is scoped the same way
- log-watcher's checks grep per-invocation files, so those are kept and
  the output is teed into both — process substitution adds no pipeline
  stage, so $! is still the command's pid the gate kills and waits on
- its one SYNCHRONOUS invocation appends after it finishes rather than
  teeing: the grep on the next line would race tee's flush

Verified, all green: chat 11/0, web-app 46/0, site 21/0, log-watcher 7/0.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
This commit is contained in:
shoney.arickathil 2026-08-27 23:53:10 +02:00
parent d87846354e
commit 7833dd5740
4 changed files with 60 additions and 12 deletions

View file

@ -27,6 +27,17 @@ ulimit -n 8192 2>/dev/null || true
W="$(mktemp -d "${TMPDIR:-/tmp}/chat-accept.XXXXXX")" W="$(mktemp -d "${TMPDIR:-/tmp}/chat-accept.XXXXXX")"
SRV="" SRV=""
# The example's server log lives at a STABLE path so a developer can
# `tail -F /tmp/chat.log` while this runs. It used to go to the per-run temp
# dir, which cleanup() deletes on exit — so there was nothing left to read and
# nothing to follow live. Truncated once here, then APPENDED by every leg with
# a banner, so one file holds the whole run in order.
SRVLOG="/tmp/chat.log"
: > "$SRVLOG"
LEG=0
LEGFROM=1
echo "server log: $SRVLOG (tail -F \"$SRVLOG\" to follow)"
cleanup() { cleanup() {
# kill EVERY server this run started, not merely the most recent $SRV: a leg # kill EVERY server this run started, not merely the most recent $SRV: a leg
# that dies before clearing SRV used to orphan a listener, which then broke # that dies before clearing SRV used to orphan a listener, which then broke
@ -111,10 +122,17 @@ PYEOF
serve() { # serve PORT [env...] — start + wait for THIS server's listener line serve() { # serve PORT [env...] — start + wait for THIS server's listener line
PORT="$1"; shift PORT="$1"; shift
: > "$W/srv.out" # stale 'listening' lines from an earlier leg lie LEG=$((LEG + 1))
"$@" "$W/app/target/chat" "$PORT" >>"$W/srv.out" 2>&1 & printf '\n===== leg %d — port %s — %s =====\n' "$LEG" "$PORT" "${*:-default env}" >>"$SRVLOG"
# readiness is searched only in THIS leg's slice: the log is appended, never
# truncated, so a 'listening' line from an earlier leg would lie
LEGFROM=$(( $(wc -l < "$SRVLOG") + 1 ))
"$@" "$W/app/target/chat" "$PORT" >>"$SRVLOG" 2>&1 &
SRV=$! SRV=$!
for _ in $(seq 1 80); do grep -q listening "$W/srv.out" 2>/dev/null && return 0; sleep 0.1; done for _ in $(seq 1 80); do
tail -n "+$LEGFROM" "$SRVLOG" 2>/dev/null | grep -q listening && return 0
sleep 0.1
done
return 1 return 1
} }
@ -400,10 +418,11 @@ if [[ -x "$ASAN" ]]; then
kill -TERM "$SRV" 2>/dev/null kill -TERM "$SRV" 2>/dev/null
for _ in $(seq 1 60); do kill -0 "$SRV" 2>/dev/null || break; sleep 0.1; done for _ in $(seq 1 60); do kill -0 "$SRV" 2>/dev/null || break; sleep 0.1; done
SRV="" SRV=""
if [[ "$r" == *functional-ok* ]] && ! grep -q "AddressSanitizer\|LeakSanitizer" "$W/srv.out"; then if [[ "$r" == *functional-ok* ]] \
&& ! tail -n "+$LEGFROM" "$SRVLOG" | grep -q "AddressSanitizer\|LeakSanitizer"; then
ok "ASan run clean (functional + drain, zero leaks)" ok "ASan run clean (functional + drain, zero leaks)"
else else
bad "asan" "$(grep -m1 -E 'ERROR|SUMMARY' "$W/srv.out" || echo "$r")" bad "asan" "$(tail -n "+$LEGFROM" "$SRVLOG" | grep -m1 -E 'ERROR|SUMMARY' || echo "$r")"
fi fi
else else
bad "asan" "runtime/build/wovm_asan missing — make -C runtime wovm-asan" bad "asan" "runtime/build/wovm_asan missing — make -C runtime wovm-asan"

View file

@ -51,6 +51,14 @@ if [[ ! -x "$WOVM" ]]; then
fi fi
WORK="$(mktemp -d "${TMPDIR:-/tmp}/lw-accept.XXXXXX")" WORK="$(mktemp -d "${TMPDIR:-/tmp}/lw-accept.XXXXXX")"
# stable, tailable log for the example app: the per-run work dir is deleted on
# exit, so a developer had nothing to follow. `tail -F /tmp/log-watcher.log`.
# Each invocation keeps its own $WORK/*.out (the checks grep those) and is
# ALSO teed here, banner-separated, so one file holds the whole run.
APPLOG="/tmp/log-watcher.log"
: > "$APPLOG"
echo "app log: $APPLOG (tail -F \"$APPLOG\" to follow)"
# LW_ACCEPT_KEEP=1 leaves the work directory (image, logs, cron.d, the # LW_ACCEPT_KEEP=1 leaves the work directory (image, logs, cron.d, the
# server's own stdout) in place — what you want the moment a check fails. # server's own stdout) in place — what you want the moment a check fails.
cleanup() { cleanup() {
@ -89,7 +97,8 @@ fi
# watcher to decide the burst is over. # watcher to decide the burst is over.
LOG="$WORK/app.log" LOG="$WORK/app.log"
: >"$LOG" : >"$LOG"
timeout -k 2 12 "$WOVM" "$IMAGE" watch "$LOG" 2 1 >"$WORK/watch.out" 2>&1 & printf '\n===== watch =====\n' >>"$APPLOG"
timeout -k 2 12 "$WOVM" "$IMAGE" watch "$LOG" 2 1 > >(tee -a "$APPLOG" >"$WORK/watch.out") 2>&1 &
WATCH_PID=$! WATCH_PID=$!
sleep 2 sleep 2
printf 'info service starting\n' >>"$LOG" printf 'info service starting\n' >>"$LOG"
@ -110,6 +119,7 @@ CRON="$WORK/cron.d"
mkdir -p "$CRON" mkdir -p "$CRON"
printf '* * * * * root /usr/bin/backup.sh > /var/log/backup.log 2>&1\n' >"$CRON/backup" printf '* * * * * root /usr/bin/backup.sh > /var/log/backup.log 2>&1\n' >"$CRON/backup"
timeout 8 "$WOVM" "$IMAGE" run "$CRON" >"$WORK/run.out" 2>&1 timeout 8 "$WOVM" "$IMAGE" run "$CRON" >"$WORK/run.out" 2>&1
{ printf '\n===== run =====\n'; cat "$WORK/run.out"; } >>"$APPLOG"
if grep -q "^SCHEDULE /var/log/backup.log" "$WORK/run.out"; then if grep -q "^SCHEDULE /var/log/backup.log" "$WORK/run.out"; then
ok "run (parsed and scheduled the cron entry)" ok "run (parsed and scheduled the cron entry)"
else else
@ -124,7 +134,8 @@ EOF
# -k: `env.stopping()` installs a SIGTERM handler that only sets a flag, and # -k: `env.stopping()` installs a SIGTERM handler that only sets a flag, and
# the serve loop is blocked in accept(), so a plain TERM is swallowed — the # the serve loop is blocked in accept(), so a plain TERM is swallowed — the
# process needs a KILL to actually stop (recorded in docs/00-status.md). # process needs a KILL to actually stop (recorded in docs/00-status.md).
timeout -k 2 20 "$WOVM" "$IMAGE" mcp "$CRON" "$WORK/cfg.json" >"$WORK/mcp.out" 2>&1 & printf '\n===== mcp =====\n' >>"$APPLOG"
timeout -k 2 20 "$WOVM" "$IMAGE" mcp "$CRON" "$WORK/cfg.json" > >(tee -a "$APPLOG" >"$WORK/mcp.out") 2>&1 &
SRV_PID=$! SRV_PID=$!
sleep 2 sleep 2
@ -256,7 +267,8 @@ if [[ -n "${LW_SOAK:-}" ]]; then
soak_mode() { soak_mode() {
local name="$1" load_fn="$2" local name="$1" load_fn="$2"
shift 2 shift 2
"$WOVM" "$IMAGE" "$@" >"$WORK/soak-$name.out" 2>&1 & printf '\n===== soak %s =====\n' "$name" >>"$APPLOG"
"$WOVM" "$IMAGE" "$@" > >(tee -a "$APPLOG" >"$WORK/soak-$name.out") 2>&1 &
local pid=$! rss0 fd0 rss1 fd1 drss dfd deadline i local pid=$! rss0 fd0 rss1 fd1 drss dfd deadline i
sleep 3 # first-touch pages and the first work cycle sleep 3 # first-touch pages and the first work cycle
if ! kill -0 "$pid" 2>/dev/null; then if ! kill -0 "$pid" 2>/dev/null; then

View file

@ -56,6 +56,11 @@ fi
PORT=$((8500 + RANDOM % 400)) PORT=$((8500 + RANDOM % 400))
DATA="$W/data"; mkdir -p "$DATA" DATA="$W/data"; mkdir -p "$DATA"
# stable, tailable server log — the per-run temp dir is deleted on exit
SRVLOG="/tmp/site.log"
: > "$SRVLOG"
echo "server log: $SRVLOG (tail -F \"$SRVLOG\" to follow)"
hit() { # path [method] [data] [token] -> "STATUS|BODY" (redirects not followed) hit() { # path [method] [data] [token] -> "STATUS|BODY" (redirects not followed)
python3 - "$PORT" "$1" "${2:-GET}" "${3:-}" "${4:-}" <<'PYEOF' python3 - "$PORT" "$1" "${2:-GET}" "${3:-}" "${4:-}" <<'PYEOF'
@ -97,7 +102,8 @@ expect() { # name got want_status want_substr
} }
serve() { serve() {
SITE_TOKEN=s3cr3t WO_DATA="$DATA" "$W/app/target/site" "$PORT" >>"$W/srv.out" 2>&1 & printf '\n===== serve — port %s =====\n' "$PORT" >>"$SRVLOG"
SITE_TOKEN=s3cr3t WO_DATA="$DATA" "$W/app/target/site" "$PORT" >>"$SRVLOG" 2>&1 &
SRV=$! SRV=$!
for _ in $(seq 1 40); do for _ in $(seq 1 40); do
[[ "$(hit /health 2>/dev/null)" == 200* ]] && return 0 [[ "$(hit /health 2>/dev/null)" == 200* ]] && return 0

View file

@ -83,9 +83,19 @@ else
fi fi
DATA="$W/data"; mkdir -p "$DATA" DATA="$W/data"; mkdir -p "$DATA"
WA_TOKEN=s3cr3t WA_IDLE_MS=600 WO_DATA="$DATA" "$W/app/target/web-app" "$PORT" >"$W/srv.out" 2>&1 & # stable, tailable server log: the per-run temp dir is deleted on exit, so a
# developer had nothing to follow. `tail -F /tmp/web-app.log` while this runs.
SRVLOG="/tmp/web-app.log"
: > "$SRVLOG"
echo "server log: $SRVLOG (tail -F \"$SRVLOG\" to follow)"
printf '===== boot — port %s =====\n' "$PORT" >>"$SRVLOG"
LEGFROM=$(( $(wc -l < "$SRVLOG") + 1 ))
WA_TOKEN=s3cr3t WA_IDLE_MS=600 WO_DATA="$DATA" "$W/app/target/web-app" "$PORT" >>"$SRVLOG" 2>&1 &
SRV=$! SRV=$!
for _ in $(seq 1 40); do grep -q listening "$W/srv.out" 2>/dev/null && break; sleep 0.1; done for _ in $(seq 1 40); do
tail -n "+$LEGFROM" "$SRVLOG" 2>/dev/null | grep -q listening && break
sleep 0.1
done
# one tiny HTTP client; python is already a repo test dependency # one tiny HTTP client; python is already a repo test dependency
hit() { # method path [body] [auth: yes|no] [content-type] -> "STATUS|BODY" hit() { # method path [body] [auth: yes|no] [content-type] -> "STATUS|BODY"
@ -467,7 +477,8 @@ for _ in $(seq 1 30); do kill -0 "$SRV" 2>/dev/null || { stopped=0; break; }; sl
SRV="" SRV=""
# ---- 15. restart persistence (WAL replay) ---- # ---- 15. restart persistence (WAL replay) ----
WA_TOKEN=s3cr3t WA_IDLE_MS=600 WO_DATA="$DATA" "$W/app/target/web-app" "$PORT" >>"$W/srv.out" 2>&1 & printf '\n===== restart (WAL replay) — port %s =====\n' "$PORT" >>"$SRVLOG"
WA_TOKEN=s3cr3t WA_IDLE_MS=600 WO_DATA="$DATA" "$W/app/target/web-app" "$PORT" >>"$SRVLOG" 2>&1 &
SRV=$! SRV=$!
sleep 0.5 sleep 0.5
expect "product survives a restart (WAL)" "$(hit GET /products)" 200 '"name":"mug"' expect "product survives a restart (WAL)" "$(hit GET /products)" 200 '"name":"mug"'