fabi/Sylpheed
1
0
Fork 0
Code Issues 9 Pull Requests Actions Packages Projects Releases Wiki Activity

re: WaitMultiple read confirmed on a live capture; XTimer is a third type

Browse Source 
23 wait frames, 30 objects, nothing unresolved -- the second deref turns every
former miss into a resolved object, as predicted. XEvent 20 / XSemaphore 9 /
XTimer 1; every WaitMultiple thread waits on a pair, and 78/79/80 and 64/65 are
worker groups sharing a handle.

%ebp does not survive as the count -- WaitMultiple reuses it at 8fc158 -- so the
array is bounded by reading until an entry stops resolving instead.

The frozen capture is still not taken: screen_id reads 'flight' at the second
capture and out to ~470s, so the mission never black-screened. The diff in the
data file is two healthy captures and is recorded as such.
This commit is contained in:
Sylpheed RE agent
2026-08-25 08:34:46 +00:00
parent 6f6ace5ec7
commit a9526749dc
3 changed files with 126 additions and 7 deletions
Download Patch File Download Diff File Expand all files Collapse all files

57
docs/re/data/waitobj-s02.txt Normal file
View File

@@ -0,0 +1,57 @@
=== healthy: 23 wait frames ===
T106 Wait n=1 xe::kernel::XEvent
T105 Wait n=1 xe::kernel::XEvent
T104 Wait n=1 xe::kernel::XEvent
T97 Wait n=1 xe::kernel::XEvent
T96 Wait n=1 xe::kernel::XEvent
T80 WaitMultiple n=2 xe::kernel::XEvent, xe::kernel::XSemaphore
T79 WaitMultiple n=2 xe::kernel::XEvent, xe::kernel::XSemaphore
T78 WaitMultiple n=2 xe::kernel::XEvent, xe::kernel::XSemaphore
T77 Wait n=1 xe::kernel::XEvent
T76 WaitMultiple n=2 xe::kernel::XEvent, xe::kernel::XTimer
T75 Wait n=1 xe::kernel::XSemaphore
T74 Wait n=1 xe::kernel::XSemaphore
T71 Wait n=1 xe::kernel::XEvent
T69 Wait n=1 xe::kernel::XSemaphore
T68 Wait n=1 xe::kernel::XEvent
T66 Wait n=1 xe::kernel::XEvent
T65 WaitMultiple n=2 xe::kernel::XEvent, xe::kernel::XSemaphore
T64 WaitMultiple n=2 xe::kernel::XEvent, xe::kernel::XSemaphore
T63 Wait n=1 xe::kernel::XSemaphore
T62 Wait n=1 xe::kernel::XEvent
T61 Wait n=1 xe::kernel::XEvent
T50 Wait n=1 xe::kernel::XEvent
T36 WaitMultiple n=2 xe::kernel::XEvent, xe::kernel::XEvent
--- objects waited on:
xe::kernel::XEvent 20
xe::kernel::XSemaphore 9
xe::kernel::XTimer 1
=== frozen: 20 wait frames ===
T106 Wait n=1 xe::kernel::XEvent
T104 Wait n=1 xe::kernel::XEvent
T97 Wait n=1 xe::kernel::XEvent
T96 Wait n=1 xe::kernel::XEvent
T80 WaitMultiple n=2 xe::kernel::XEvent, xe::kernel::XSemaphore
T79 WaitMultiple n=2 xe::kernel::XEvent, xe::kernel::XSemaphore
T78 WaitMultiple n=2 xe::kernel::XEvent, xe::kernel::XSemaphore
T77 Wait n=1 xe::kernel::XEvent
T76 WaitMultiple n=2 xe::kernel::XEvent, xe::kernel::XTimer
T75 Wait n=1 xe::kernel::XSemaphore
T74 Wait n=1 xe::kernel::XSemaphore
T71 Wait n=1 xe::kernel::XEvent
T66 Wait n=1 xe::kernel::XEvent
T65 WaitMultiple n=2 xe::kernel::XEvent, xe::kernel::XSemaphore
T64 WaitMultiple n=2 xe::kernel::XEvent, xe::kernel::XSemaphore
T63 Wait n=1 xe::kernel::XSemaphore
T62 Wait n=1 xe::kernel::XEvent
T61 Wait n=1 xe::kernel::XEvent
T50 Wait n=1 xe::kernel::XEvent
T36 WaitMultiple n=2 xe::kernel::XEvent, xe::kernel::XEvent
--- objects waited on:
xe::kernel::XEvent 18
xe::kernel::XSemaphore 8
xe::kernel::XTimer 1
=== healthy -> frozen ===
xe::kernel::XEvent 20 -> 18 CHANGED
xe::kernel::XSemaphore 9 -> 8 CHANGED
xe::kernel::XTimer 1 -> 1

55
docs/re/mission-freeze-resume-spin.md
View File

@@ -913,3 +913,58 @@ only 10/18 reliable. The unwind was never the problem; the parser was.
`freeze_waitobj.sh` now parses the function name and frame index out of the
backtrace instead of assuming frame 3, and applies the matching rule to each.
## ✅ 2026-08-25 — the WaitMultiple read confirmed, and a third object type
Ran it. The prediction from the section above holds: applying the second deref
to `WaitMultiple` frames turns every one of the former "misses" into a resolved
object. Full table in `data/waitobj-s02.txt`; **23 wait frames, 30 objects, and
nothing unresolved.**
| waited on | count |
|---|---|
| `xe::kernel::XEvent` | 20 |
| `xe::kernel::XSemaphore` | 9 |
| `xe::kernel::XTimer` | 1 |
`XTimer` is new — it never appeared before because the only thread waiting on
one (T76) is a `WaitMultiple` thread, and those were exactly the frames the old
parser read wrongly.
Every `WaitMultiple` thread waits on a **pair**, never more: six on
(`XEvent`, `XSemaphore`), one on (`XEvent`, `XTimer`), one on
(`XEvent`, `XEvent`). Threads 78/79/80 share one `objects` array contents and
64/65 another, so these are worker groups on a common handle.
### 🟡 `%ebp` is not a usable count
The plan was to bound the array with the count in `%ebp`. It reads `0x0` on
every frame, and the disassembly says why: `WaitMultiple` **reuses `ebp`** at
`8fc158` (`mov 0x10(%rax),%ebp`) once it is past the prologue, so the count is
gone by the time these captures interrupt. The array is bounded instead by
reading until an entry stops resolving — past the last real object the words are
`0x0` and gdb reports `Cannot access memory at address 0x0`. Same self-validating
rule as everywhere else here, and it needs no register.
## 🔴 The frozen capture STILL has not been taken — the freeze did not happen
The second capture is labelled `frozen` and is not. `screen_id` reads **`flight`**
at the capture (`green=0.0140 mean=(30.3,31.4,36.4)`), 367 s into the mission,
and three follow-up screenshots out to **~470 s of flight** also read `flight`
with a drifting frame mean, so the picture was still moving. The mission simply
did not black-screen this run.
So the `healthy -> frozen` diff in the data file is **two healthy captures**, and
its `20 -> 18` / `9 -> 8` is three threads (T105, T68, T69) having exited — normal
churn, not a freeze signature. Recorded as-is rather than presented as a result.
**This also puts a question against the "black-screens at ~4.5 min" bound** used
to plan these runs. One confound is named and not ruled out: this run is under
gdb, which slows the emulator (boot to title took 207 s), so 470 s of wall-clock
may be well short of 270 s of *guest* time. Until that is measured the honest
statement is that the ~270 s figure is a wall-clock observation from ungated runs
and does not reproduce under gdb, not that it is wrong.
**Next:** get a freeze under gdb at all — either drive the mission to the end
condition that produces it instead of waiting on a clock, or measure guest time
under gdb so the wait can be set in the units the freeze actually follows.

21
tools/re-capture/waitobj_report.py
View File

@@ -6,7 +6,12 @@ freeze_waitobj.sh), so they are parsed separately:
Wait rbx = this -> [rbx] is the vtable
WaitMultiple rbx = XObject** -> [[rbx+8i]] is object i's vtable
ebp = count -> entries past the count are garbage
%ebp holds the count only at the prologue: WaitMultiple reuses it at 8fc158
(`mov 0x10(%rax),%ebp`), and it reads 0 at the point these captures interrupt.
So the array length is NOT taken from a register -- entries are read until one
stops resolving, which is the same self-validating rule used for everything
else here.
Every reading is validated the same way: gdb's `info symbol` must resolve it to
a `vtable for ...` symbol. A polymorphic object's first word always is one, so
@@ -50,14 +55,16 @@ def report(tag):
if not recs: return collections.Counter()
tally = collections.Counter()
for r in recs:
n = r['count'] if r['kind'] == 'WaitMultiple' and r['count'] else len(r['slots'])
n = min(n, len(r['slots']))
live = r['slots'][:n]
# take entries up to the first one that did not resolve
live = []
for s_ in r['slots']:
if s_ is None: break
live.append(s_)
for s in live:
tally[s if s else '<unresolved>'] += 1
print(' T%-4s %-13s count=%-4s %s' % (
r['th'], r['kind'], r['count'] if r['count'] is not None else '-',
', '.join(s or '?' for s in live) or '(nothing readable)'))
print(' T%-4s %-13s n=%d %s' % (
r['th'], r['kind'], len(live),
', '.join(live) or '(nothing readable)'))
print(' --- objects waited on:')
for k, c in tally.most_common():
print(' %-45s %d' % (k, c))