From f6470854706aac582c41c07473ba9a9833e408e5 Mon Sep 17 00:00:00 2001 From: Sylpheed RE agent Date: Wed, 19 Aug 2026 12:12:40 +0000 Subject: [PATCH] docs: withdraw the resume-refused lead - kHighFrequency waits are simply unlogged The 1663 refused resumes on thread F80001D8 looked like a second lost resume of the kind fixed earlier today. They are not. That thread DID execute - the log carries its XThread::Execute line, guest entry 82FFE6C0 - and then 137000 lines of silence. The silence proves nothing: KeWaitForSingleObject and NtWaitForSingleObjectEx are declared kBlocking, kHighFrequency, and PrintKernelCall skips every kHighFrequency export unless --log_high_frequency_kernel_calls=true, which defaults to false. A thread parked in a wait is invisible in these logs. So the boring reading is the right one: the guest kicks a worker that is blocked ON AN OBJECT, and Resume returns false because the thread is not SUSPENDED. That is what a refused resume means, exactly as suspected before the count made it look interesting. Method note kept in the doc, because it is the reason one conclusion survives and the other does not: the title-loader finding rested on 00:00:00 host CPU time from ps -L and on the fix changing behaviour 5/5 against 1/5 - not on log silence. In this codebase log silence alone is never sufficient evidence that a thread is idle. Also records a grep error of mine that briefly produced "zero kernel calls, ever": the pattern ^[dikwF!]> missed the K> kernel prefix. Caught before it was written down, and it changed the conclusion. --- docs/re/BACKLOG.md | 10 ++++++--- docs/re/title-crash-stl-tree.md | 38 ++++++++++++++++++++++++++++++++- 2 files changed, 44 insertions(+), 4 deletions(-) diff --git a/docs/re/BACKLOG.md b/docs/re/BACKLOG.md index 3c38d3e3..f42ec884 100644 --- a/docs/re/BACKLOG.md +++ b/docs/re/BACKLOG.md @@ -767,9 +767,13 @@ guest C++ throw — identical frames 6 s apart, no new dumps, 400 % CPU. So the blocker moved from "cannot reach a mission" to "the mission freezes". Cheapest next test: the crash page shows a **complete on-disc cache produces no throw**, and the cache is only 40 MB with `.partial`/`.cold-rebuilt` leftovers nearby — -one boot to warm it, one to re-test. New lead recorded there too: the -resume-refused diagnostic fires 1 671 times on this path, 1 663 on one thread, -against ~7 on the menu path — specific, and explicitly not yet claimed as a bug. +one boot to warm it, one to re-test. 🔴 The resume-refused lead (1 663 on one +thread) is **REFUTED**: that thread did execute, and `KeWaitForSingleObject` / +`NtWaitForSingleObjectEx` are `kHighFrequency`, which is unlogged unless +`--log_high_frequency_kernel_calls=true` — so a parked thread is invisible and +the refusals are just the guest kicking a worker blocked on an object. Method +note: the title-loader finding rested on **host CPU time**, not log silence, +which is why it stands and this did not. What blocked it before was **the cache-flush crash**, not navigation — measured 2026-08-19. `tools/re-capture/tutorial_launch.sh` (which retries whole boots, diff --git a/docs/re/title-crash-stl-tree.md b/docs/re/title-crash-stl-tree.md index 9c29d1df..22762f70 100644 --- a/docs/re/title-crash-stl-tree.md +++ b/docs/re/title-crash-stl-tree.md @@ -287,7 +287,43 @@ the warship counters, the controller diagram So the honest status is: reachable, renders, unusable for a capture. -### 🔬 A new lead, not a claim +### 🔴 That lead is REFUTED (same day) + +**Withdrawn.** The 1 663 refused resumes on `F80001D8` are not evidence of a +second lost resume, and the reason is a property of this codebase's logging that +is worth knowing on its own. + +`F80001D8` **did** execute. The log has exactly one line from it — + +``` +K> F80001D8 XThread::Execute thid 41 (handle=F80001D8, 'XThread82FFE6C0 (F80001D8)', native=82FFE6C0) +``` + +— and then 137 000 lines of silence. That silence proves nothing: +`KeWaitForSingleObject` and `NtWaitForSingleObjectEx` are declared +`kBlocking, kHighFrequency`, and `PrintKernelCall` skips every `kHighFrequency` +export unless `--log_high_frequency_kernel_calls=true`, which defaults to +**false**. A thread parked in a wait is completely invisible here. + +So the consistent reading is the boring one: the guest is kicking a worker that +is blocked **on an object**, and `Resume` returns false because the thread is not +*suspended* — a different mechanism entirely. Refused resumes are the expected +result, exactly as first suspected before the count made it look interesting. + +⚠️ **Method note worth keeping.** The title-loader conclusion did *not* rest on +log silence — it rested on **`00:00:00` host CPU time** from `ps -L`, plus the +fix changing behaviour 5/5 against 1/5. That is why it survives and this one does +not. In this codebase, log silence alone is never sufficient evidence that a +thread is idle. + +(A grep of mine briefly said "zero kernel calls, ever" because the pattern +`^[dikwF!]>` missed the `K>` kernel prefix. Corrected before it was written down, +and the conclusion changed as a result.) + +To settle what `F80001D8` actually waits on, one boot with +`--log_high_frequency_kernel_calls=true` would show it. + +### 🔬 The lead as originally recorded, kept for the reasoning The `XThread::Resume: host resume was refused` diagnostic added with the threading fix fires **1 671 times** on this path — and **1 663 of them are the