.. SPDX-License-Identifier: GPL-2.0 ================================================================================ arch/wasm32 bisect postmortems ================================================================================ :Status: Living document. Append-only. Each entry is the postmortem for one bisection whose lesson was structural enough to warrant a §15 row or a §15.2-shaped rule in ``docs/ARCHITECTURE.md``. Why this file exists. Bisections that take more than a day produce a specific kind of knowledge: not "what fixed the bug" (that's the commit) and not "what the rule is going forward" (that's the architecture doc), but *the empirical chain of hypotheses ruled out along the way*. Every wrong guess we ruled out is a path the next person debugging an adjacent symptom won't have to walk. Without this file, that knowledge dies in the chat transcript. Each entry is structured the same way: * Phase the bisect happened in. * Symptom as it first appeared (the kernel-side line of dmesg, the test that timed out, the trap message, etc.). * What we thought it was, and why we thought so. * The bisection moves, in order, with the observation that moved each one. * The structural lesson (the rule that, applied earlier, would have prevented the bisect from being necessary). * Pointer to the §15 row or §15.2-shaped subsection that codifies the lesson going forward. -------------------------------------------------------------------------------- B1. K4 — L1_CACHE_BYTES include-order layout split -------------------------------------------------------------------------------- :Phase: K4 (cooperative scheduling, kthreadd online). :Closed by: ``arch/wasm32/include/asm/cache.h`` (new), removing ``generic-y += cache.h`` from ``arch/wasm32/include/asm/Kbuild``, removing the duplicate ``L1_CACHE_BYTES`` define from ``arch/wasm32/include/asm/processor.h``. :Codified by: ``docs/ARCHITECTURE.md §15.2`` ("ODR via macro asymmetry: arch primitives that overlap with asm-generic"). Symptom ~~~~~~~ K4 had landed Asyncify + ``__wasm32_switch_to`` + ``__wasm32_yield``; the K3 acceptance test (kernel boots through ``mm_init`` / ``sched_init`` / ``rest_init``) still passed; the new K4 acceptance shape was meant to be "rest_init runs, kthreadd is reachable, runs at least one full park loop, kernel_init panics with 'No working init found.'" The kernel instead went silent after :: rest_init → cpu_startup_entry → do_idle → schedule_idle → __schedule → context_switch → __wasm32_switch_to → asyncify_start_unwind [first unwind] → wasm_start_kernel (returns from start_kernel via unwind) → __wasm32_yield (enters cooperative dispatcher) → wasm32_rq_dequeue → kthreadd → __wasm32_kthread_dispatch_first → kthread (kernel/kthread.c) → schedule_preempt_disabled → __schedule → put_prev_task / pick_next_task → context_switch → switch_to → __wasm32_switch_to ... — and "host CPU usage 96.0%" on a 5-second idle window. The expected shape was "CPU usage near zero" (kthreadd parks on its wait queue; ``__wasm32_park_until_runnable`` does ``Atomics.wait`` on ``__sched_wakeup_word``). 96% means *something* in the kernel was busy-spinning. First hypotheses (ruled out in order) ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ 1. **"Asyncify state-machine drives are wrong."** Wrote a sibling probe (``tools/k4-binaryen-asyncify-probe/``) that asserts the exact 9-byte assert pattern Binaryen 125 injects around ``__wasm32_switch_to``. Probe passed — the strip tool is doing what it advertises; the asserts are removed cleanly; the state machine transitions are valid. *Not the bug.* 2. **"__wasm32_yield's outer loop hits state==NONE on a retry path we hadn't reasoned through."** Added one-shot dmesg first-call markers at every observable transition (``__wasm32_yield entered``, ``__wasm32_park_until_runnable first call``, ``arch_cpu_idle first call``, ``copy_thread first call``). The kernel reached ``copy_thread first call`` — confirming kthreadd's task_struct was allocated and ``copy_thread`` was running — but never reached the ``__wasm32_yield entered`` marker. *The kernel was stuck inside copy_thread itself*, not in the cooperative dispatcher. 3. **"copy_thread is in an infinite slab-allocator retry loop."** Instrumented every ``kmalloc(THREAD_SIZE, ...)`` / ``kmalloc(ASYNCIFY_DATA_SIZE, ...)`` return. Both succeeded immediately. The next-line ``__wasm32_asyncify_init_buf`` succeeded. The hang was after ``copy_thread`` returned. *Not the bug.* 4. **"copy_process is the one busy-spinning."** Followed the call chain: ``copy_thread`` returns to ``copy_process`` (kernel/fork.c). Added a marker per major ``copy_process`` block. The kernel reached "after copy_thread returned" and silently froze before "in copy_signal." The intervening code is mostly ``spin_lock_irq`` / list manipulation. A single ``spin_lock_irq(¤t->sighand->siglock)`` in ``copy_signal`` was the suspect. *Getting close.* 5. **"sighand_struct's init_sighand has wrong linkage."** In ``kernel/init_task.c``, ``init_sighand`` is declared ``static``. Theorized that external references resolved to address 0. Dumped ``&init_sighand`` via printk before reaching the spin_lock; address was nonzero and sensible. *Not the bug — but the test added a critical observation for what came next.* 6. **"sighand_struct's siglock is at the wrong field offset."** Compared ``offsetof(struct sighand_struct, siglock)`` from ``kernel/init_task.c`` and from ``arch/wasm32/kernel/head.c``. Both reported 0. *Not the bug.* 7. **"current->sighand is the wrong pointer."** This was the move that broke the case open. Added:: pr_info("sighand_struct addr: init=%px current=%px sizeof_task=%zu off_sighand=%zu\\n", &init_sighand, current->sighand, sizeof(struct task_struct), offsetof(struct task_struct, sighand)); in ``kernel/init_task.c`` AND in ``arch/wasm32/kernel/head.c``. Both files print the same struct's offset. They reported **different values**: ``init/main.c`` saw ``offsetof(task_struct, sighand) = 1320``; ``head.c`` saw 1288. ``sizeof(struct task_struct)`` differed too: 1408 vs 1344. Two TUs had different ideas about ``struct task_struct``'s layout. **The crash moves when you add a printk** because adding a printk reshuffles the include chain of the TU containing the print, and the TU that now reads the bytes is a different TU than the one that wrote them. Resolution ~~~~~~~~~~ The struct field that differed in offset was ``sighand``. Walked backwards through ``struct task_struct``: every field before some specific cross-cutting point matched between the two TUs; every field after differed by exactly 32 bytes. The cross-cutting point was ``task_struct.se`` (``struct sched_entity``). The size of ``sched_entity`` differed: 384 bytes in ``init/main.c``, 352 in ``head.c``. Inside ``sched_entity`` is:: struct sched_avg avg ____cacheline_aligned; The ``____cacheline_aligned`` attribute pads up to the next ``L1_CACHE_BYTES``-aligned boundary. If ``L1_CACHE_BYTES`` is 64 in one TU and 32 in another, the field's offset within ``sched_entity`` differs by 32 bytes; ``sched_entity``'s total size differs by 32 bytes; every field after ``task_struct.se`` shifts by 32 bytes; ``task_struct``'s ``sizeof`` differs by 32. The reason ``L1_CACHE_BYTES`` had two values: the wasm port defined ``L1_CACHE_BYTES = 64`` in ``arch/wasm32/include/asm/processor.h`` (because the K4 spec'd the cooperative-scheduler runqueue node as ``____cacheline_aligned`` with a 64-byte expectation), AND ``arch/wasm32/include/asm/Kbuild`` declared ``generic-y += cache.h``, which routed ``#include `` to ``include/asm-generic/cache.h`` whose default is ``L1_CACHE_SHIFT = 5`` → ``L1_CACHE_BYTES = 32``. Whichever header was included *last* in a given TU's chain won. The fix is structural, not local: own ``arch/wasm32/include/asm/cache.h`` exclusively, remove ``generic-y += cache.h``. The §15.2 rule in ``docs/ARCHITECTURE.md`` generalizes this from one constant to the whole class. Structural lesson ~~~~~~~~~~~~~~~~~ *Arch primitives that exist in both `arch//include/asm/` and `include/asm-generic/` are an ABI hazard.* The C preprocessor does not detect or warn about the disagreement; the C compiler emits TU-correct layouts; the linker resolves by name, not by layout. The runtime symptom is "the crash moves when you add diagnostics," which is the *worst* kind of bug because every act of debugging changes the bug's apparent location. Prevention is structural: either ``generic-y +=`` and rely on the default, or own the header and remove ``generic-y``, but never both for the same constant. See ``docs/ARCHITECTURE.md §15.2``. Diagnostic technique that worked ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ The key move was move 7 above: *print the same struct's layout from two different TUs and compare*. Once two TUs reported different ``offsetof`` or ``sizeof`` for what should be one struct, the entire class of bugs (mismatched layout) was visible without further guessing. This is a generalizable technique for any "the crash moves with diagnostics" symptom: pick a struct on the suspect code path, print its layout from each TU on that path, look for disagreement. Time cost ~~~~~~~~~ ~2 days of incremental bisection. Cost of the move-1-through-6 hypotheses was approximately one bad assumption each: that the crash location reported was the crash *cause* location. Move 7 abandoned that assumption. Cost saved going forward: every K-phase that adds an arch header mirrored in ``asm-generic`` now checks §15.2 before merge. If the discipline holds, this bisect doesn't recur.