79e11a3e76
Run 8 died 54 s into its boot and this time bash named it: "176880 Killed" on the run-canary line, which is SIGKILL. So the third failure mode is not an internal fault - something outside the process is killing it. And it is still not the OOM killer. Checked immediately after: oom_kill remained 0 and the allocation-stall counter did not move from 4421, so during run 8 the cgroup never reached its limit (5.35 GB of 7 GiB), and the host had 13.8 GB available. Two kills, no OOM evidence either time. Rather than keep guessing after the fact, freeze_watch.sh now samples host MemAvailable, cgroup memory.current and oom_kill on every poll and dumps the last five samples when the process disappears - so the next occurrence carries its own contemporaneous reading. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01PMRJjbxLqZtsb5Vb7KunPE
73 lines
3.4 KiB
Bash
Executable File
73 lines
3.4 KiB
Bash
Executable File
#!/usr/bin/env bash
|
|
# Wait for the in-mission freeze and capture the evidence at the moment it lands.
|
|
#
|
|
# Written because catching it by hand costs a tool call every 25 s and the freeze
|
|
# takes anywhere from ten seconds to never: roughly half the runs that reach
|
|
# flight freeze, and the other half do not
|
|
# (docs/re/mission-freeze-resume-spin.md).
|
|
#
|
|
# "Frozen" is two screenshots byte-identical (frozen.py); it is checked ONLY
|
|
# while the flight HUD is still on screen, because the GAME OVER screen animates
|
|
# and a run that ended there is not a freeze.
|
|
#
|
|
# On detection it snapshots what the stuck-wait probe has said, so the comparison
|
|
# against the healthy-run baseline (one thread polling one Event) is made from
|
|
# the same instant rather than reconstructed later.
|
|
set -u
|
|
export HOME=/sylph-home/re
|
|
DISP="${DISPLAY:-:98}"
|
|
SD="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)"
|
|
LOG="${1:-/sylph-home/re/shots/probe-canary.stdout}"
|
|
OUT="${2:-/sylph-home/re/logs/freeze-evidence.txt}"
|
|
DEADLINE=$(( SECONDS + ${3:-1800} ))
|
|
: > "$OUT"
|
|
|
|
# Sample memory every poll, so a run that DIES has a contemporaneous reading
|
|
# instead of a post-mortem guess. Two runs were SIGKILLed from outside with the
|
|
# cgroup's oom_kill counter reading 0 both times, and by the time anything was
|
|
# read the pressure (if that is what it was) had passed.
|
|
mem_line() {
|
|
local avail cur
|
|
avail=$(awk '/MemAvailable/{print int($2/1024)}' /proc/meminfo)
|
|
cur=$(( $(cat /sys/fs/cgroup/memory.current 2>/dev/null || echo 0) / 1048576 ))
|
|
local oom
|
|
oom=$(awk '/^oom_kill /{print $2}' /sys/fs/cgroup/memory.events 2>/dev/null)
|
|
echo "t=${SECONDS}s host_avail=${avail}MiB cgroup=${cur}MiB oom_kill=${oom}"
|
|
}
|
|
|
|
while [ $SECONDS -lt $DEADLINE ]; do
|
|
mem_line >> "${OUT%.txt}-mem.log"
|
|
if ! pgrep -x xenia_canary >/dev/null; then
|
|
{ echo "EMULATOR GONE at ${SECONDS}s"; echo "last memory samples:";
|
|
tail -5 "${OUT%.txt}-mem.log"; } | tee -a "$OUT"; exit 4
|
|
fi
|
|
if python3 "$SD/frozen.py" 5 >/dev/null; then
|
|
if python3 -c "import sys; sys.path.insert(0,'$SD'); import frozen; sys.exit(0 if frozen.in_flight() else 1)"; then
|
|
{
|
|
echo "FROZEN IN FLIGHT at ${SECONDS}s"
|
|
echo
|
|
echo "=== stuck-wait probe: (thread, object) pairs ==="
|
|
grep -oE 'thread [0-9A-F]+ has timed out [0-9]+ times in a row on object [0-9A-F]+ \(type [0-9]+\)' "$LOG" \
|
|
| sed -E 's/has timed out [0-9]+ times in a row //' | sort | uniq -c | sort -rn
|
|
echo
|
|
echo "=== last 12 stuck-wait lines ==="
|
|
grep 'wait-probe' "$LOG" | tail -12
|
|
echo
|
|
echo "=== call-rate probe: per-thread rates in the last 20 windows ==="
|
|
grep 'wait-rate' "$LOG" | tail -20 \
|
|
| sed -E 's/.*thread ([0-9A-F]+) called KeWaitForSingleObject ([0-9]+) times in ([0-9]+) ms over ([0-9]+) distinct.*last result ([0-9A-F]+)/thread \1 \2 calls\/\3ms \4 objects result \5/'
|
|
echo
|
|
echo "=== call-rate: highest single window per thread, whole run ==="
|
|
grep 'wait-rate' "$LOG" \
|
|
| sed -E 's/.*thread ([0-9A-F]+) called KeWaitForSingleObject ([0-9]+) times.*/\1 \2/' \
|
|
| sort -k1,1 -k2,2nr | awk '!seen[$1]++ {print " thread " $1 " peak " $2 " calls/window"}'
|
|
} | tee -a "$OUT"
|
|
exit 0
|
|
fi
|
|
echo "frozen but NOT in flight (mission over) at ${SECONDS}s" | tee -a "$OUT"
|
|
exit 5
|
|
fi
|
|
sleep 20
|
|
done
|
|
echo "NO FREEZE within ${3:-1800}s" | tee -a "$OUT"; exit 1
|