forked from Ports/goldeneye-pc-port
D287 M-152: correct false evidence citation, static architecture trace
scratch/d287_freeze_gdb.txt, cited as this finding's freeze-time evidence, does not contain it -- grepped for every specific number the write-up quotes (frame 17616, the three heartbeat stall times) and got zero hits. The file on disk is an unrelated clean normal-exit capture. No real freeze-time thread state has actually been analyzed for this bug yet; corrected the entry so a future session doesn't treat it as narrowed-and-confirmed. Also traced the consumer/producer architecture statically (mainThread's only OS_MESG_BLOCK send is rsp.c:271's osSendMesg into the scheduler's cmdQ; GE_D60 doesn't cover sends), and found portHeartbeatCheck hard-caps at 3 reports/process -- "heartbeat stopped logging" in the original write-up is that cap, not new evidence. Both quirks added to porting-notes.md. No code change -- diagnostic-only pass, needs a real live capture next.
This commit is contained in:
1 parent
695ff7ec09
commit
8d42ac5ee2
2 files changed
+16
-1
No files matched your search
@@ -10871,7 +10871,9 @@ crash class C2 (Facility `-level_34`, Runway `-level_35`): `import_texture_i8` A
|
||||
|
||||
**User-confirmed real, non-self-recovering freeze on Windows (M-141, 2026-09-15/16) after ~15-20 minutes with no input, triggered by clicking back into the window.** Caught live under `tools_pc/debug.ps1` (gdb-attached), evidence preserved at `scratch/d287_freeze_gdb.txt`. Last real `frame N rendered` log line: frame 17616. The heartbeat (`portHeartbeatCheck`) then fired 3 times with a **growing** stall (8001ms → 13017ms → 18021ms, `frames=17616` unchanged all 3 times) and then stopped logging entirely, while the VI-retrace pacemaker (`D51 vi post #N`) kept incrementing at its normal ~60 Hz rate for well over 100 more real seconds until the user closed the window — i.e. the pacemaker/OS-timer side is alive, the sim/render side is genuinely wedged, not the D286 shape (which self-recovered after one dump). **Different from D286**: no explosion/level-streaming context (idle + refocus, not combat), and the growing-then-silent heartbeat pattern (vs. D286's single fire-then-recover) points at a different mechanism. **Leading lead, not yet confirmed:** at freeze time, `gfxFrameMsgQ` (`src/init.c`, the scheduler's 32-slot client completion queue, registered via `osScAddClient`) shows `valid=32/32` — completely full — while the VI-retrace queue (8-slot) is not (`valid=1/8`). A full *client* queue with the producer (scheduler) still ticking implies the **consumer** (the main thread's `osRecvMesg(&gfxFrameMsgQ, ...)` in the frame loop) stopped draining it — consistent with the main/render thread blocking on something else (a lock, a GL call, a Windows message-pump stall) during or after a long-idle refocus, not with the scheduler itself stalling. Not yet identified what that something is. A pre-existing, currently-unused diagnostic (`GE_D60`, `port/src/libultra.c:630+`) already watches `gfxFrameMsgQ` receives and looks like the right next probe to enable. **Next, concrete:** reproduce with `GE_D60=1` (and ideally `GE_INPUTLOG=1`) running under `debug.ps1`, leave the window idle+unfocused 15-20 min, refocus, and once frozen `bt full` the actual game/render thread (not just the auto-dump's generic `WaitForMultipleObjects` frames for `shedThread`/`audioThread`) to find what it's blocked on. Cross-ref D134's superficially-similar-sounding-but-different mechanism (a different, 8-slot queue, already fixed) — do not assume the same fix applies here without confirming the actual blocked call site.
|
||||
|
||||
**Status (from §F table):** OPEN — one confirmed occurrence, real (not self-recovering), not root-caused; `gfxFrameMsgQ` full is a lead, not a confirmed cause.
|
||||
**M-152 correction (2026-09-16, static-only pass — verified directly, don't skip this): `scratch/d287_freeze_gdb.txt` does NOT contain the evidence this entry describes.** Grepped the file on disk for `17616`/`8001ms`/`13017ms`/`18021ms`/`portHeartbeatCheck` — zero hits. What the file actually holds is a **clean normal-exit capture**: boot through `frame 20700 rendered` / `D51 vi post #20821`, then `[INFO] video: window closed`, all threads exiting with code 0, `Inferior 1 exited normally`, and gdb's post-mortem `No stack.`/`The program has no registers now.` under `BACKTRACE`/`REGISTERS` — i.e. the user closed the window normally in whatever run produced this specific file; it is not a freeze capture at all. The frame-17616/heartbeat numbers cited above must come from a different run that was never saved, or got overwritten by this file under the same name. **Practical upshot: no real freeze-time thread state has actually been analyzed yet** — everything upstream in this entry citing `d287_freeze_gdb.txt` as "evidence" is describing a file that no longer supports that claim; treat the freeze mechanism as still fully open, not "narrowed and just needs confirming." Architecture traced (still useful, static-only, no game execution): the sole `OS_MESG_BLOCK` **send** anywhere in mainThread's per-frame path is `osSendMesg(sched_cmdQ, ...)` at `src/game/rsp.c:271` (end of `rspGfxTaskStart`), which per `port/src/libultra.c:605-628` does an unbounded `pthread_cond_wait` if the scheduler's 8-slot `cmdQ` is full; the scheduler thread (`__scMain`, `src/sched.c:245-310`) drains that queue unconditionally every retrace tick (`__scHandleRetrace`, `sched.c:323-325`) and separately stuffs `gfxFrameMsgQ` via NOBLOCK sends every retrace (`sched.c:352`) — consistent with the "queue fills because the consumer stopped receiving" shape, but a missed-wakeup race on the `cmdQ` condvar is a hypothesis, not evidence; no second "idle+refocus"-shaped blocking call was found in mainThread's path (SDL event pumping runs on a separate host thread, `port/src/main.c:243-246`, ruling out message-pump starvation as a mainThread blocker). Also noted: `portHeartbeatCheck` (`port/src/libultra.c:218`) hard-caps at **3 reports total per process lifetime** by design — "heartbeat stopped logging" (cited above as evidence the mechanism differs from D286) is that cap firing, not a signal the hang changed shape; don't read silence from this diagnostic as meaningful without accounting for the cap. `GE_D60` (`port/src/libultra.c:630-642`) only validates `gfxFrameMsgQ` receive *content* isn't clobbered — it does not instrument sends or `sc->cmdQ`, so it alone won't catch a `cmdQ`-side stall. Proposed for the next real capture (not yet added to tree): a `GE_D287` env-gated variant of `portHeartbeatCheck` that keeps reporting (with a full thread/queue dump via the existing `crashDumpThreads`) for the whole stall instead of stopping after 3, run alongside `GE_D60` under `debug.ps1` for the actual 15-20 min idle+refocus repro — this is the only way to get mainThread's real blocked call site.
|
||||
|
||||
**Status (from §F table):** OPEN — the `d287_freeze_gdb.txt` file this entry cited as evidence turned out to be a normal-exit capture, not a freeze capture (M-152 correction); no real freeze-time thread state has been analyzed yet. `gfxFrameMsgQ` full remains an architecturally-plausible lead (traced statically: consumer-side stall via an unbounded `pthread_cond_wait` in `rsp.c:271`'s `osSendMesg`, if the scheduler's `cmdQ` fills), not a confirmed cause. Needs a fresh live capture — ideally with a raised/env-gated heartbeat-report cap (see above) plus `GE_D60` — to get mainThread's actual backtrace at freeze time.
|
||||
|
||||
## D288 — Silo intro: a huge, flat-shaded, untextured brown/tan triangle sweeps across the frame during the camera pan down the missile shaft (M-141, user report —…
|
||||
|
||||
|
||||
@@ -702,6 +702,19 @@ through a converter or a runtime bswap fixup reads scrambled.
|
||||
Confirm the `src/game/` side is clean first (item ID, resource-table
|
||||
entry, model header, generic equip/gate pipeline) before spending time
|
||||
in fast3d — but once it is, look there, not back at the decomp logic.
|
||||
- **`portHeartbeatCheck` (`port/src/libultra.c:218`) hard-caps at 3
|
||||
reports total per process lifetime, by design** ("stop after a few
|
||||
reports"). When chasing a long-idle hang (D287), "the heartbeat stopped
|
||||
logging" is that cap firing, not evidence the hang resolved, worsened,
|
||||
or changed mechanism — don't read silence from this diagnostic as a
|
||||
signal. Gate a raised/unlimited report count behind its own env var for
|
||||
these investigations instead of trusting the default cap's silence.
|
||||
- **Before citing a `scratch/*.log`/`.txt` capture as "evidence" in a
|
||||
finding, grep it for the specific numbers/strings the write-up claims**
|
||||
(D287): a file with the right name on disk is not proof it holds the
|
||||
claimed capture — this one turned out to be an unrelated normal-exit
|
||||
run, not the freeze it was cited for, and the mistake propagated
|
||||
through the entry unnoticed until a later static pass checked.
|
||||
- **D74 wrap-block is DEAD CODE** (`gfx_pc.cpp:1546/1551`): guard is
|
||||
`cms & G_TX_WRAP` but `G_TX_WRAP == 0`, so always false (line 1887 does
|
||||
it right with `cms == G_TX_WRAP`). And if it did run it indexes
|
||||
|
||||
Reference in new issue
Block a user