6900ebe5ca
Caught the freeze by waiting for the event (frozen.py + in_flight) instead of sleeping a guessed interval; freeze_waitobj.sh splits into boot/watch so the wait is not capped by one Bash call. Verified hard: a frame minutes later is byte-identical to the capture. Healthy vs frozen, same run: 20 -> 24 wait frames, XEvent 19 -> 23, XSemaphore 8 -> 7. The signature is per-thread -- 17 of 24 threads sit on the exact object they were on, four previously-running threads park, and T74/T75 move off a semaphore onto an event. So the freeze is not a whole-emulator stall. Also corrects the previous entry's test: screen_id reads 'flight' during a freeze by design, which is why frozen.py exists. Re-testing the saved frames says that run was genuinely healthy, but it was right by luck. heavy_read.py added to test whether the instrument provokes the freeze: I/O is free (371 MB in 0.1s, page cache), the cost is Python-level CPU. One data point -- 670s clean, then frozen 54s after the inducer started -- recorded as n=1, not as causation.
130 lines
5.7 KiB
Bash
Executable File
130 lines
5.7 KiB
Bash
Executable File
#!/usr/bin/env bash
|
|
# Read WHICH object the guest threads are waiting on, HEALTHY vs FROZEN.
|
|
#
|
|
# Groundwork (mission-freeze-resume-spin.md): the waiting functions keep their
|
|
# interesting argument in %rbx, and .eh_frame lets gdb restore callee-saved
|
|
# registers during the unwind, so no DWARF and no rebuild are needed.
|
|
#
|
|
# TWO functions end up in these backtraces and %rbx does NOT mean the same
|
|
# thing in each -- reading them as one set is what produced the earlier
|
|
# "8 of 18 threads have an unreadable rbx" claim (waitobj-two-functions.md):
|
|
#
|
|
# XObject::Wait(this, ...) 8fbc90: mov %rdi,%rbx -> rbx = this
|
|
# XObject::WaitMultiple(count, objects, .) 8fbfc0: mov %rsi,%rbx -> rbx = objects[]
|
|
# mov %edi,%ebp -> ebp = count
|
|
#
|
|
# So a Wait frame is read with one deref and a WaitMultiple frame with two, and
|
|
# every reading is checked by `info symbol`: a polymorphic object's first word
|
|
# is a vtable, so a value that does not resolve to a `vtable for ...` symbol is
|
|
# discarded rather than interpreted.
|
|
#
|
|
# Captures TWICE so the comparison is within-run: once while the mission is
|
|
# healthy, once frozen. The frozen one is reached by WAITING FOR THE EVENT, not
|
|
# by a clock -- measured onsets are 27/45/83/183/255s (median ~83), only about
|
|
# half of runs freeze at all, and the "~270s" figure this script used to sleep
|
|
# for was never a real bound.
|
|
#
|
|
# "Frozen" is frozen.py's test -- two byte-identical frames while the flight HUD
|
|
# is still up. It is NOT `screen_id == flight` being false: a frozen mission
|
|
# still classifies as `flight`, which is the whole reason frozen.py exists.
|
|
#
|
|
# Subcommands, because the boot and the wait do not fit one Bash call but the
|
|
# emulator survives BETWEEN calls in a turn:
|
|
# freeze_waitobj.sh boot [fly_s] boot, fly, capture `healthy`, leave running
|
|
# freeze_waitobj.sh watch [secs] poll for the freeze, capture `frozen`
|
|
set -u
|
|
export HOME=/sylph-home/re SDL_AUDIODRIVER=dummy DISPLAY=:98
|
|
export PYTHONPATH=/sylph-home/.local/lib/python3.12/site-packages
|
|
export XENIA_BIN=/sylph-home/re/bin/gdb-wrap/xenia_canary
|
|
SD="$(cd "$(dirname "$0")" && pwd)"
|
|
FLY1="${1:-200}" # healthy checkpoint
|
|
FLY2="${2:-140}" # extra seconds -> lands past the ~270s black-screen
|
|
CMD=/tmp/gdb-cmd; OUT=/tmp/gdb-out.log
|
|
|
|
sleepfor(){ python3 -c "import time,sys; time.sleep(float(sys.argv[1]))" "$1"; }
|
|
|
|
capture(){ # capture <tag>
|
|
local tag="$1" pid before
|
|
pid=$(pgrep -x gdb | head -1)
|
|
[ -n "$pid" ] || { echo "[$tag] no gdb"; return 2; }
|
|
before=$(wc -c < "$OUT")
|
|
screenshot "/tmp/fz-$tag.png" >/dev/null 2>&1
|
|
echo "[$tag] screen: $(python3 "$SD/screen_id.py" "/tmp/fz-$tag.png" 2>/dev/null | head -1)"
|
|
kill -INT "$pid"; sleepfor 3
|
|
{ echo 'echo === BT '"$tag"' ===\n'; echo 'thread apply all bt 6'
|
|
echo 'echo === END BT ===\n'; } >> "$CMD"
|
|
sleepfor 10
|
|
tail -c +$((before + 1)) "$OUT" > "/tmp/fz-bt-$tag.txt"
|
|
# emit per-thread reads, with the frame index and the function taken from the
|
|
# backtrace itself rather than assumed
|
|
TAG="$tag" python3 - "/tmp/fz-bt-$tag.txt" <<'PY' >> "$CMD"
|
|
import os,re,sys
|
|
txt=open(sys.argv[1],errors='replace').read(); tag=os.environ['TAG']
|
|
cur=None; n=0
|
|
for line in txt.splitlines():
|
|
m=re.match(r'Thread (\d+) ',line)
|
|
if m: cur=m.group(1); continue
|
|
if not cur: continue
|
|
f=re.search(r'#(\d+)\s+0x[0-9a-f]+ in xe::kernel::XObject::(WaitMultiple|Wait)\(',line)
|
|
if not f: continue
|
|
fr,kind=f.group(1),f.group(2)
|
|
print(r'echo === %s T%s %s f%s ===\n'%(tag,cur,kind,fr))
|
|
print('thread %s'%cur); print('frame %s'%fr)
|
|
if kind=='Wait':
|
|
print('info registers rbx')
|
|
print('info symbol *(unsigned long*)$rbx')
|
|
else:
|
|
print('info registers rbx rbp')
|
|
for i in range(4):
|
|
print('info symbol *(unsigned long*)*(unsigned long*)($rbx+%d)'%(8*i))
|
|
cur=None; n+=1
|
|
print(r'echo === END OBJ %s ===\n'%tag); print('continue')
|
|
sys.stderr.write('[%s] %d wait frames\n'%(tag,n))
|
|
PY
|
|
sleepfor 14
|
|
tail -c +$((before + 1)) "$OUT" > "/tmp/fz-obj-$tag.txt"
|
|
local epid; epid=$(pgrep -x xenia_canary | head -1)
|
|
[ -n "$epid" ] && cp "/proc/$epid/maps" "/tmp/fz-maps-$tag.txt" 2>/dev/null
|
|
echo "[$tag] captured"
|
|
}
|
|
|
|
MODE="${1:-boot}"
|
|
FLY="${2:-}"
|
|
|
|
if [ "$MODE" = watch ]; then
|
|
SECS="${FLY:-500}"
|
|
pgrep -x xenia_canary >/dev/null || { echo "NO EMULATOR"; exit 1; }
|
|
end=$((SECONDS + SECS))
|
|
while [ $SECONDS -lt $end ]; do
|
|
pgrep -x xenia_canary >/dev/null || { echo "EMULATOR GONE at ${SECONDS}s"; exit 4; }
|
|
if python3 "$SD/frozen.py" 5 >/dev/null 2>&1; 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 of this watch"
|
|
capture frozen
|
|
python3 "$SD/waitobj_report.py" healthy frozen
|
|
echo "FREEZE WAITOBJ DONE"; exit 0
|
|
fi
|
|
echo "frozen but NOT in flight (mission over) at ${SECONDS}s"; exit 5
|
|
fi
|
|
sleepfor 12
|
|
done
|
|
echo "NO FREEZE within ${SECS}s (still animating)"; exit 1
|
|
fi
|
|
|
|
# ---- boot mode ----
|
|
FLY="${FLY:-150}"
|
|
"$SD/launch_mission.sh" fly || { echo "BOOT FAILED"; exit 1; }
|
|
CFG=/tmp/nav-fz.json
|
|
for t in 1 2 3; do
|
|
python3 "$SD/pad.py" set "rt=1" >/dev/null 2>&1 || true; sleepfor 3
|
|
python3 "$SD/pad.py" clear >/dev/null 2>&1 || true
|
|
if python3 "$SD/entities2.py" self 0x130 "$CFG" >/dev/null 2>&1; then
|
|
SYLPH_HUNT=1 SYLPH_KEEPOUT=1400 nohup python3 "$SD/pilot.py" "$CFG" 3000 \
|
|
</dev/null >/tmp/fz-pilot.log 2>&1 & echo "--- pilot flying"; break
|
|
fi
|
|
done
|
|
echo "--- flying ${FLY}s to the healthy control capture"
|
|
sleepfor "$FLY"; capture healthy
|
|
python3 "$SD/waitobj_report.py" healthy
|
|
echo "BOOT PHASE DONE -- emulator left running; now: freeze_waitobj.sh watch"
|