5fb4da4c43
v2 counts every KeWaitForSingleObject call per thread per second, tracks how many distinct objects it saw, and logs the last result. Its HEALTHY baseline is a result on its own: over a full 22-minute run the main thread cleared 500 calls/s in 224 separate windows, peaking at 1235 calls/s over up to THIRTEEN distinct objects, and the last result was X_STATUS_SUCCESS in all 314 windows. Not one timeout. So the game normally does hundreds of successful waits a second across many objects - exactly the blind spot v1 could not see, and the reason a timeout-streak counter reported the same single poller whether the game was frozen or healthy. Stated as a consequence rather than a triumph: 500/s is NOT self-selecting, since the main thread clears it constantly, so the freeze signal has to be a different shape - a thread far above 1235/s, a new thread, or a window whose result is not SUCCESS. That still needs a frozen sample; run 5 ended in GAME OVER at ~22 min without freezing. freeze_watch.sh now summarises the rate probe per thread when it captures. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01PMRJjbxLqZtsb5Vb7KunPE
58 lines
2.6 KiB
Bash
Executable File
58 lines
2.6 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"
|
|
|
|
while [ $SECONDS -lt $DEADLINE ]; do
|
|
if ! pgrep -x xenia_canary >/dev/null; then
|
|
echo "EMULATOR GONE at ${SECONDS}s" | 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
|