From ae3f37d3ec6c68bf76920de321f2cf3acef746b0 Mon Sep 17 00:00:00 2001 From: Sylpheed RE agent Date: Wed, 19 Aug 2026 10:41:43 +0000 Subject: [PATCH] tools+docs: locate the lost resume, and a title test that is neither too narrow nor too loose The stalled loader thread is a lost wakeup in Xenia's POSIX threading, fixed on the canary branch as a60fe7d11 and written up here. A thread created suspended publishes state_ and suspend_count_ in two separate lock scopes, and Resume() waits only for state_ before testing suspend_count_ == 0 - so a resumer in the gap drops the resume and the thread waits forever. The Linux XThread::Resume discards that false, which is why the guest saw success. On the first clean boot after the fix the loader thread is the CALLER on 20 kernel-call lines and issues 4 ResolvePath reads. Every failed boot before it had exactly zero of both. Stated plainly as not shown: that boots now reach the menu RELIABLY. One post-fix boot, and it is confounded by the harness. Which is the second half. skip_intro.sh's title test has now been wrong twice in opposite directions: originally one absolute pixel (625,618) - a 1280x720 coordinate against the 1279x675 game surface, so it read the copyright line and timed out with the title on screen - and then my replacement, screen_id.py, which is too loose and called the SQUARE ENIX publisher logo "title" 151s into a boot, spending the script's single press there. is_title.py now counts the green (A) glyph over the whole frame: geometry-independent and specific, measured at 0 pixels on the logo and 1520 on a real title. --- docs/re/BACKLOG.md | 18 +++++- docs/re/canary-scripted-input-traps.md | 81 ++++++++++++++++++++++++++ tools/re-capture/is_title.py | 26 +++++++++ tools/re-capture/skip_intro.sh | 15 ++--- 4 files changed, 130 insertions(+), 10 deletions(-) create mode 100755 tools/re-capture/is_title.py diff --git a/docs/re/BACKLOG.md b/docs/re/BACKLOG.md index 90e8a0b..fefe116 100644 --- a/docs/re/BACKLOG.md +++ b/docs/re/BACKLOG.md @@ -161,9 +161,21 @@ See [`structures/ui-composable-bundles.md`](structures/ui-composable-bundles.md) **`00:00:00` host CPU time** while the process runs at 546 %. A spinning thread burns CPU; this one never ran. A lost resume is a race, which is the first explanation that fits the ~1-in-3 success rate. - **Next probe:** Xenia's `XThread` create/resume pair — can a resume land before - the host thread starts waiting? And capture one *successful* boot with kernel - logging, to say whether the guest sequence differs at all. + ✅ **LOCATED AND FIXED** (canary `a60fe7d11`): `threading_posix.cc` publishes a + suspended thread's `state_` and its `suspend_count_` in **two separate lock + scopes**, and `Resume()` waits only for `state_` before testing + `if (suspend_count_ == 0) return false`. A resumer in that gap drops the + resume; the thread then waits on the count forever. The Linux `XThread::Resume` + discards the `false`, so the guest saw success. Fixed by publishing both under + one lock and waiting without releasing it. On the first clean boot after, the + loader thread is the **caller** on 20 kernel-call lines with 4 `ResolvePath` + reads — every failure before had **zero** of both. + 🟡 **Still to show:** that boots now reach the menu *reliably*. The post-fix + boot is confounded — `skip_intro.sh`'s title test has been wrong twice (an + absolute pixel against the wrong surface size, then `screen_id.py` matching the + SQUARE ENIX logo). Now `tools/re-capture/is_title.py` counts the green Ⓐ glyph: + 0 px on the logo, 1520 on a real title. A before/after reliability count over + several boots is the remaining work. See [`canary-scripted-input-traps.md`](canary-scripted-input-traps.md). * ❔ **Blend mode.** Everything is straight alpha-over. The near-white flash quads (`0xf0ffffff`) and coloured ones (`0x60ff0000`) may be additive. The diff --git a/docs/re/canary-scripted-input-traps.md b/docs/re/canary-scripted-input-traps.md index e51c9a8..ed0603f 100644 --- a/docs/re/canary-scripted-input-traps.md +++ b/docs/re/canary-scripted-input-traps.md @@ -520,3 +520,84 @@ and this boot path succeeds about **1 time in 3**. that cheap. * ❔ Guest entry `0x821748F0` is now a named RE target: whatever the menu loader is. + + +## ✅ Located and fixed: a lost resume in Xenia's POSIX threading (2026-08-19) + +**Status:** ✅ `CONFIRMED` as the mechanism, by reading the code against the +measurement. ✅ The fix demonstrably changes the emulator's behaviour in the +predicted way. 🟡 **End-to-end menu reliability is NOT yet demonstrated** — one +post-fix boot, and it is confounded (below). + +### The race, exactly + +`threading_posix.cc` starts a thread created suspended like this: + +```cpp +{ lock; state_ = create_suspended ? kSuspended : kRunning; notify_all(); } + // ← lock released +if (create_suspended) { lock; suspend_count_ = 1; wait(count == 0); } +``` + +and `Resume()` is: + +```cpp +WaitStarted(); // waits only for state_ != kUninitialized +lock; +if (suspend_count_ == 0) { return false; } // ← the resume is DROPPED +``` + +Two separate lock scopes, with the state published **before** the suspend count. +A resumer that arrives in the gap sees a started thread with count 0, drops the +resume, and returns `false`. The new thread then sets the count to 1 and waits on +it forever. + +`XThread::Resume`'s Linux path discards that `false` — the Windows path turns it +into `X_STATUS_UNSUCCESSFUL` — so the guest was told the resume succeeded. The +failure was invisible from both sides. + +### Why it fits everything measured + +| observation | explained | +|---|---| +| loader thread makes **zero** kernel calls | it never leaves the CV wait | +| its host thread has **00:00:00** CPU | ditto — a spin would burn CPU | +| the guest handler looks perfect | it is; the resume it issued was dropped | +| success rate ~**1 in 6** | it is a race | +| `NtResumeThread` returns success | the Linux path ignores the `false` | + +### The fix, and what it showed + +Publish `state_` and `suspend_count_` under **one** lock and wait without ever +releasing it, so a resumer past `WaitStarted()` always observes 1 +(canary `a60fe7d11`). + +On the first clean boot afterwards, the same loader thread is the **caller** on +**20** kernel-call lines and issues **4** `ResolvePath` asset reads. Every failed +boot before the fix had exactly **zero** of both. That is the predicted change, +and it is the strongest evidence available short of a reliability run. + +### What is honestly not shown + +* 🟡 **That boots now reach the menu reliably.** The post-fix boot drifted into + the attract loop because `skip_intro.sh` fired its single press at 145 s, and + the run before it pressed on the **SQUARE ENIX publisher logo** — see below. A + clean before/after reliability count still needs several boots. +* ⚠️ **`host resume was refused` is not by itself a defect.** Resuming a thread + that is not suspended legitimately returns false, and the log fires ~7 times in + a normal boot. It is a breadcrumb, not an alarm. + +### A harness regression I introduced and then corrected + +`skip_intro.sh`'s title test has now been wrong twice, in opposite directions: + +1. the original probed **one absolute pixel** `(625,618)` for the green Ⓐ glyph — + a 1280×720 coordinate against the 1279×675 game surface, so it read the + copyright line and timed out with the title on screen; +2. my replacement used `screen_id.py`, which is **too loose**: it called the + SQUARE ENIX logo "title" 151 s into a boot and the script spent its one press + there. + +Now `tools/re-capture/is_title.py` **counts** the green glyph over the whole +frame — geometry-independent and specific. Measured: **0** pixels on the SQUARE +ENIX logo, **1 520** on a real title, threshold 400. diff --git a/tools/re-capture/is_title.py b/tools/re-capture/is_title.py new file mode 100755 index 0000000..be87808 --- /dev/null +++ b/tools/re-capture/is_title.py @@ -0,0 +1,26 @@ +#!/usr/bin/env python3 +"""Is this frame the interactive title screen? Exit 0 if yes. + +Counts the pixels of the **green (A) glyph** in "PRESS (A) BUTTON" anywhere in +the frame. That is the one thing only the interactive title has, and counting is +geometry-independent — unlike the single absolute pixel this replaced, which was +a 1280x720 coordinate being sampled against the 1279x675 game surface and always +read the copyright line. + +`screen_id.py` is too loose for this job on its own: it called the SQUARE ENIX +publisher logo "title" 151 s into a boot, and skip_intro spent its one press +there. Measured on a real title frame: 1442 glyph pixels, centred near (622,572). + + is_title.py FRAME.png [min_pixels] +""" +import sys + +import numpy as np +from PIL import Image + +a = np.asarray(Image.open(sys.argv[1]).convert("RGB"), dtype=int) +r, g, b = a[:, :, 0], a[:, :, 1], a[:, :, 2] +n = int(((g > 130) & (g - r > 45) & (g - b > 45)).sum()) +need = int(sys.argv[2]) if len(sys.argv) > 2 else 400 +print(f"green-glyph px {n} (need {need})") +sys.exit(0 if n >= need else 1) diff --git a/tools/re-capture/skip_intro.sh b/tools/re-capture/skip_intro.sh index b984f76..6c7d43f 100755 --- a/tools/re-capture/skip_intro.sh +++ b/tools/re-capture/skip_intro.sh @@ -43,13 +43,14 @@ while [ $SECONDS -lt $deadline ]; do [ -n "$(alive)" ] || { echo "EMULATOR GONE at ${SECONDS}s"; exit 4; } d=$(compare -metric RMSE /tmp/f1.png /tmp/f2.png null: 2>&1 | sed 's/ .*//' | cut -d. -f1) d=${d:-0} - # Classify the whole frame, do NOT probe one absolute pixel. The old test - # sampled (625,618) for the green (A) glyph, which is a coordinate from a - # 1280x720 grab; `screenshot` now returns the 1279x675 GAME SURFACE, where - # that point lands on the copyright line and reads (8,17,31). The symptom was - # a 600s TIMEOUT with the title sitting on screen the entire time — measured - # 2026-08-19, with screen_id.py calling it "title" on the same frames. - if [ "$(python3 "$SD_SI/screen_id.py" /tmp/f2.png | awk '{print $1}')" = "title" ]; then + # COUNT the green (A) glyph over the whole frame; do not probe one absolute + # pixel and do not trust screen_id.py here. The pixel probe used a 1280x720 + # coordinate against the 1279x675 game surface and always read the copyright + # line (600s TIMEOUT with the title on screen). screen_id.py fixed that and + # then over-matched the other way: it called the SQUARE ENIX publisher logo + # "title" 151s into a boot, and this script spent its one press there. + # is_title.py counts glyph pixels, which only the interactive title has. + if python3 "$SD_SI/is_title.py" /tmp/f2.png >/dev/null 2>&1; then echo "TITLE at ${SECONDS}s -> A"; tapA; exit 0 fi # DO NOT tap through the movies. This branch used to, and for a long time it