211 lines · plain
1.. SPDX-License-Identifier: GPL-2.02 3================================================================================4arch/wasm32 bisect postmortems5================================================================================6 7:Status: Living document. Append-only. Each entry is the postmortem for8 one bisection whose lesson was structural enough to warrant a9 §15 row or a §15.2-shaped rule in ``docs/ARCHITECTURE.md``.10 11Why this file exists. Bisections that take more than a day produce a12specific kind of knowledge: not "what fixed the bug" (that's the13commit) and not "what the rule is going forward" (that's the14architecture doc), but *the empirical chain of hypotheses ruled out15along the way*. Every wrong guess we ruled out is a path the next16person debugging an adjacent symptom won't have to walk. Without this17file, that knowledge dies in the chat transcript.18 19Each entry is structured the same way:20 21* Phase the bisect happened in.22* Symptom as it first appeared (the kernel-side line of dmesg, the23 test that timed out, the trap message, etc.).24* What we thought it was, and why we thought so.25* The bisection moves, in order, with the observation that moved26 each one.27* The structural lesson (the rule that, applied earlier, would have28 prevented the bisect from being necessary).29* Pointer to the §15 row or §15.2-shaped subsection that codifies30 the lesson going forward.31 32--------------------------------------------------------------------------------33B1. K4 — L1_CACHE_BYTES include-order layout split34--------------------------------------------------------------------------------35 36:Phase: K4 (cooperative scheduling, kthreadd online).37:Closed by: ``arch/wasm32/include/asm/cache.h`` (new), removing38 ``generic-y += cache.h`` from39 ``arch/wasm32/include/asm/Kbuild``, removing the duplicate40 ``L1_CACHE_BYTES`` define from41 ``arch/wasm32/include/asm/processor.h``.42:Codified by: ``docs/ARCHITECTURE.md §15.2`` ("ODR via macro asymmetry:43 arch primitives that overlap with asm-generic").44 45Symptom46~~~~~~~47 48K4 had landed Asyncify + ``__wasm32_switch_to`` + ``__wasm32_yield``;49the K3 acceptance test (kernel boots through ``mm_init`` /50``sched_init`` / ``rest_init``) still passed; the new K4 acceptance51shape was meant to be "rest_init runs, kthreadd is reachable, runs at52least one full park loop, kernel_init panics with 'No working init53found.'" The kernel instead went silent after ::54 55 rest_init → cpu_startup_entry → do_idle → schedule_idle56 → __schedule → context_switch → __wasm32_switch_to57 → asyncify_start_unwind [first unwind]58 → wasm_start_kernel (returns from start_kernel via unwind)59 → __wasm32_yield (enters cooperative dispatcher)60 → wasm32_rq_dequeue → kthreadd61 → __wasm32_kthread_dispatch_first → kthread (kernel/kthread.c)62 → schedule_preempt_disabled → __schedule63 → put_prev_task / pick_next_task → context_switch64 → switch_to → __wasm32_switch_to ...65 66— and "host CPU usage 96.0%" on a 5-second idle window. The expected67shape was "CPU usage near zero" (kthreadd parks on its wait queue;68``__wasm32_park_until_runnable`` does ``Atomics.wait`` on69``__sched_wakeup_word``). 96% means *something* in the kernel was70busy-spinning.71 72First hypotheses (ruled out in order)73~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~74 751. **"Asyncify state-machine drives are wrong."** Wrote a sibling76 probe (``tools/k4-binaryen-asyncify-probe/``) that asserts the77 exact 9-byte assert pattern Binaryen 125 injects around78 ``__wasm32_switch_to``. Probe passed — the strip tool is doing what79 it advertises; the asserts are removed cleanly; the state machine80 transitions are valid. *Not the bug.*81 822. **"__wasm32_yield's outer loop hits state==NONE on a retry path83 we hadn't reasoned through."** Added one-shot dmesg first-call84 markers at every observable transition (``__wasm32_yield entered``,85 ``__wasm32_park_until_runnable first call``, ``arch_cpu_idle first86 call``, ``copy_thread first call``). The kernel reached87 ``copy_thread first call`` — confirming kthreadd's task_struct was88 allocated and ``copy_thread`` was running — but never reached the89 ``__wasm32_yield entered`` marker. *The kernel was stuck inside90 copy_thread itself*, not in the cooperative dispatcher.91 923. **"copy_thread is in an infinite slab-allocator retry loop."**93 Instrumented every ``kmalloc(THREAD_SIZE, ...)`` /94 ``kmalloc(ASYNCIFY_DATA_SIZE, ...)`` return. Both succeeded95 immediately. The next-line ``__wasm32_asyncify_init_buf`` succeeded.96 The hang was after ``copy_thread`` returned. *Not the bug.*97 984. **"copy_process is the one busy-spinning."** Followed the call99 chain: ``copy_thread`` returns to ``copy_process`` (kernel/fork.c).100 Added a marker per major ``copy_process`` block. The kernel101 reached "after copy_thread returned" and silently froze before "in102 copy_signal." The intervening code is mostly ``spin_lock_irq`` /103 list manipulation. A single ``spin_lock_irq(¤t->sighand->siglock)``104 in ``copy_signal`` was the suspect. *Getting close.*105 1065. **"sighand_struct's init_sighand has wrong linkage."** In107 ``kernel/init_task.c``, ``init_sighand`` is declared108 ``static``. Theorized that external references resolved to address109 0. Dumped ``&init_sighand`` via printk before reaching the110 spin_lock; address was nonzero and sensible. *Not the bug — but111 the test added a critical observation for what came next.*112 1136. **"sighand_struct's siglock is at the wrong field offset."**114 Compared ``offsetof(struct sighand_struct, siglock)`` from115 ``kernel/init_task.c`` and from ``arch/wasm32/kernel/head.c``. Both116 reported 0. *Not the bug.*117 1187. **"current->sighand is the wrong pointer."** This was the move119 that broke the case open. Added::120 121 pr_info("sighand_struct addr: init=%px current=%px sizeof_task=%zu off_sighand=%zu\\n",122 &init_sighand, current->sighand,123 sizeof(struct task_struct),124 offsetof(struct task_struct, sighand));125 126 in ``kernel/init_task.c`` AND in ``arch/wasm32/kernel/head.c``.127 Both files print the same struct's offset. They reported128 **different values**: ``init/main.c`` saw ``offsetof(task_struct,129 sighand) = 1320``; ``head.c`` saw 1288. ``sizeof(struct130 task_struct)`` differed too: 1408 vs 1344. Two TUs had different131 ideas about ``struct task_struct``'s layout. **The crash moves132 when you add a printk** because adding a printk reshuffles the133 include chain of the TU containing the print, and the TU that now134 reads the bytes is a different TU than the one that wrote them.135 136Resolution137~~~~~~~~~~138 139The struct field that differed in offset was ``sighand``. Walked140backwards through ``struct task_struct``: every field before some141specific cross-cutting point matched between the two TUs; every142field after differed by exactly 32 bytes. The cross-cutting point143was ``task_struct.se`` (``struct sched_entity``). The size of144``sched_entity`` differed: 384 bytes in ``init/main.c``, 352 in145``head.c``.146 147Inside ``sched_entity`` is::148 149 struct sched_avg avg ____cacheline_aligned;150 151The ``____cacheline_aligned`` attribute pads up to the next152``L1_CACHE_BYTES``-aligned boundary. If ``L1_CACHE_BYTES`` is 64153in one TU and 32 in another, the field's offset within154``sched_entity`` differs by 32 bytes; ``sched_entity``'s total155size differs by 32 bytes; every field after ``task_struct.se``156shifts by 32 bytes; ``task_struct``'s ``sizeof`` differs by 32.157 158The reason ``L1_CACHE_BYTES`` had two values: the wasm port159defined ``L1_CACHE_BYTES = 64`` in160``arch/wasm32/include/asm/processor.h`` (because the K4 spec'd161the cooperative-scheduler runqueue node as ``____cacheline_aligned``162with a 64-byte expectation), AND163``arch/wasm32/include/asm/Kbuild`` declared ``generic-y += cache.h``,164which routed ``#include <asm/cache.h>`` to165``include/asm-generic/cache.h`` whose default is166``L1_CACHE_SHIFT = 5`` → ``L1_CACHE_BYTES = 32``. Whichever header167was included *last* in a given TU's chain won.168 169The fix is structural, not local: own ``arch/wasm32/include/asm/cache.h``170exclusively, remove ``generic-y += cache.h``. The §15.2 rule in171``docs/ARCHITECTURE.md`` generalizes this from one constant to the172whole class.173 174Structural lesson175~~~~~~~~~~~~~~~~~176 177*Arch primitives that exist in both `arch/<arch>/include/asm/` and178`include/asm-generic/` are an ABI hazard.* The C preprocessor does179not detect or warn about the disagreement; the C compiler emits180TU-correct layouts; the linker resolves by name, not by layout. The181runtime symptom is "the crash moves when you add diagnostics,"182which is the *worst* kind of bug because every act of debugging183changes the bug's apparent location. Prevention is structural:184either ``generic-y +=`` and rely on the default, or own the header185and remove ``generic-y``, but never both for the same constant. See186``docs/ARCHITECTURE.md §15.2``.187 188Diagnostic technique that worked189~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~190 191The key move was move 7 above: *print the same struct's layout from192two different TUs and compare*. Once two TUs reported different193``offsetof`` or ``sizeof`` for what should be one struct, the entire194class of bugs (mismatched layout) was visible without further195guessing. This is a generalizable technique for any "the crash196moves with diagnostics" symptom: pick a struct on the suspect code197path, print its layout from each TU on that path, look for198disagreement.199 200Time cost201~~~~~~~~~202 203~2 days of incremental bisection. Cost of the move-1-through-6204hypotheses was approximately one bad assumption each: that the205crash location reported was the crash *cause* location. Move 7206abandoned that assumption.207 208Cost saved going forward: every K-phase that adds an arch header209mirrored in ``asm-generic`` now checks §15.2 before merge. If the210discipline holds, this bisect doesn't recur.211