re: WaitMultiple read confirmed on a live capture; XTimer is a third type
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:
57
docs/re/data/waitobj-s02.txt
Normal file
57
docs/re/data/waitobj-s02.txt
Normal 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
|
||||
@@ -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.
|
||||
|
||||
Reference in New Issue
Block a user