187 lines
16 KiB
Markdown
187 lines
16 KiB
Markdown
# K-PUSH Dictionary Shadowing Bug — Full Report
|
||
**Date:** 2026-07-04
|
||
**Branch:** `lithosananke`
|
||
**Commits:** `326cee47` (root cause captured) → `99358e2c` (fix) → `347fb726` (trap cleanup) → `6816063f` (loader-experiment revert) → `379bf16c` (three-arch acceptance)
|
||
**Author:** Captain Bob / Claude Code
|
||
|
||
---
|
||
|
||
## Symptom
|
||
|
||
`K-PUSH` (`capsules/fleet-k.4th`, block 4401) crashed on its first call with:
|
||
|
||
```
|
||
execute_colon_word: NULL cell in 'K-PUSH' after '(start)' at 0x80267d10
|
||
```
|
||
|
||
Three consecutive zeroed cells preceded the fault (`0x80267d00`, `0x80267d08`, `0x80267d10` — all `val=0x0`). The crash was:
|
||
|
||
- **Intermittent** — did not reproduce on every run of the same binary.
|
||
- **Delayed** — always occurred ~173 real seconds after boot, on K-PUSH's *first invocation* (via `TRIPOD-TEST → K-INIT... CD-TICK → K-BUMP → K-PUSH`), never during capsule load.
|
||
- **Worst on riscv64** — the slowest-booting architecture under QEMU/TCG, though the underlying flaw was architecture-neutral.
|
||
|
||
This is the same bug reported earlier in this session (see prior report `ARTEMIS-BAM-ACCEPTANCE-20260703.md`, which had misattributed a *different*, riscv64-only dict-hash divergence to disk-boot-path differences — that finding was correct and unrelated; this document covers the K-PUSH crash specifically).
|
||
|
||
---
|
||
|
||
## Investigation timeline
|
||
|
||
### False start: mid-compile forward-reference race
|
||
|
||
The first hypothesis was that `dict_reorganize_buckets_by_heat()` — a wall-clock-gated (1 Hz) background pass that re-sorts dictionary buckets by execution heat — could fire *during* compilation of a multi-line colon definition and corrupt it mid-flight. This led to an "atomic rollback" change in the capsule loader (`exec_block_with_retry()`, commit `a8ea30e7`): if an interior line of a `: ... ;` definition failed while `vm->mode == MODE_COMPILE`, the loader would roll `vm->latest` back to before the definition started and retry the whole line-span as one unit (bounded to 3 attempts) instead of the old per-line defer.
|
||
|
||
This was the wrong tree. Two problems surfaced:
|
||
|
||
1. It never actually fixed K-PUSH. Tracing showed block 4401 (fleet-k.4th) loaded with **zero errors** — the rollback path never engaged for it. K-PUSH's `DictEntry` compiled cleanly at load time; whatever corrupted its body happened *after* compilation, not during it.
|
||
2. It broke Hermes. `capsules/hermes/init.4th` has several blocks (4115, 4116, 4117, 4119, 4120, 4126) with permanently-dead interior references (`COMMON-CH`, `CH-REAP-SAFE`, `HERA-NOTIFY-SPAWN`, `LSHIFT`, `CH-MINT-ID`, `USE` — words that never exist in Hermes's dictionary, confirmed present in the pre-existing baseline too). The old per-line defer silently dropped just those lines and kept the rest of each definition working. The atomic loader retried each whole definition 3× and then discarded it *entirely* — deleting `CD-INIT`, `HERMES-K`, and the `CH-*` helpers that terminate Hermes's message-scan loop. The very next boot that lived long enough to reach `K-FLEET → VM-CALL 'Hermes'` hung forever inside `CH-SCAN` (one run reached 2.9 trillion ticks / 826MB of trace before being killed).
|
||
|
||
This detour is preserved in git history (`a8ea30e7`) and was cleanly reverted (`6816063f`) once the real fix made it unnecessary.
|
||
|
||
### Root-cause capture (traps)
|
||
|
||
Temporary instrumentation was added (later stripped in `347fb726`) at four points:
|
||
- `FILL` (`memory_words.c`) — logged any zero-fill whose address range touched the crash window.
|
||
- `ALLOT` (`dictionary_words.c`) — logged every `HERE` movement.
|
||
- `CREATE` / `:` (`defining_words.c`, `vm.c`) — logged the data-field address assigned to every new word.
|
||
- The interpreter's outer dispatch (`vm_core.c`) — logged, on every lookup of the literal name `VM-COUNT`, which `DictEntry*` was returned and what value its data field held.
|
||
|
||
These traps reproduced the failure and captured it precisely (log `logs/20260704-155745`, referenced in commit `326cee47`).
|
||
|
||
---
|
||
|
||
## Root cause
|
||
|
||
**Two `DictEntry` objects legitimately named `VM-COUNT` coexist in the same dictionary bucket:**
|
||
|
||
1. A **kernel C primitive**, registered at VM bootstrap (`src/starkernel/capsule/mama_forth_words.c:830`):
|
||
```c
|
||
void mama_word_vm_count(VM *vm) {
|
||
vm_push(vm, (cell_t)capsule_vm_registry_count());
|
||
}
|
||
```
|
||
This returns the **live count of VMs born so far** — a value that changes over the boot sequence (1 → 2 → 3 as Hera, then Artemis, then Hermes come up). It is registered *twice* (`mama_forth_words.c:1069` and `1096` — once into the base FORTH vocabulary, once again after switching to the MAMA vocabulary), so there are actually two of these primitive entries.
|
||
|
||
2. A **FORTH capsule constant**, defined later at boot (`capsules/compudynamics.4th:7`):
|
||
```forth
|
||
3 CONSTANT VM-COUNT
|
||
```
|
||
This is a fixed value — 3, the permanent size of the Tripod fleet (Hera + Hermes + Artemis) — meant to shadow the primitive for all capsule code from that point forward.
|
||
|
||
Boot order (`capsules/init.4th`) matters:
|
||
```
|
||
S" compudynamics.4th" EXEC <- line 17: capsule CONSTANT VM-COUNT (=3) defined
|
||
S" lib.4th" EXEC
|
||
S" fleet-k.4th" EXEC <- line 21: CREATE K-WINDOWS VM-COUNT K-WINDOW-DEPTH * CELLS ALLOT
|
||
S" process.4th" EXEC
|
||
S" Artemis" BIRTH <- line 24: registry count becomes 2
|
||
S" Hermes" BIRTH <- line 26: registry count becomes 3
|
||
```
|
||
|
||
**`fleet-k.4th` loads and sizes its arrays *before* Artemis and Hermes are born** — at that exact moment, `capsule_vm_registry_count()` genuinely is 1 (only Hera/Mama registered). Under correct FORTH-79 semantics, the newer capsule constant (3) should *always* win a name lookup over the older primitive — dictionary word definitions shadow by recency, newest-first. That invariant is exactly what broke.
|
||
|
||
### Why the invariant broke
|
||
|
||
`dict_reorganize_buckets_by_heat()` (`dictionary_heat_optimization.c`) is a background maintenance pass, gated purely on wall-clock time (`now_ns - vm->last_bucket_reorg_ns < 1,000,000,000`, i.e. it may run once per real second, from anywhere in the interpreter loop). It `qsort`s each first-character hash bucket by `execution_heat` — genuinely useful for the physics-driven runtime's lookup optimization, but it **destroys newest-first ordering** as a side effect. Nothing about a heat-sorted bucket preserves "which entry was defined most recently."
|
||
|
||
Multiple lookup paths assumed newest-first bucket order and did a plain first-match scan of whatever order the bucket happened to be in:
|
||
|
||
- `hotwords_cache_lookup()`'s Stage-2 bucket fallback (the actual primary resolution engine for most lookups).
|
||
- `vm_find_word()`'s naive fallback scan.
|
||
- `dict_find_word_heat_aware()`'s three-tier heat-percentile scan (first-match-by-heat — the most direct violation of the invariant).
|
||
|
||
If the heat reorg placed either kernel-primitive `VM-COUNT` entry ahead of the capsule constant's entry in the `'V'` bucket — plausible, since the primitives are registered and exercised (elsewhere in the kernel) far earlier and more often than the just-defined constant — any of these paths could return the primitive instead of the constant. Because this depends on exactly when the 1 Hz reorg gate fires relative to fleet-k.4th's load, the outcome is **timing-dependent and intermittent** — worse on riscv64 simply because its QEMU/TCG boot is slowest, giving the reorg pass the most opportunities to land in the failure window.
|
||
|
||
### The two-phase corruption mechanism
|
||
|
||
1. **Phase 1 — load time (~5–6s real boot time).** `fleet-k.4th` executes `CREATE K-WINDOWS VM-COUNT K-WINDOW-DEPTH * CELLS ALLOT`. If the primitive wins the lookup, `VM-COUNT` evaluates to **1** instead of 3. `K-WINDOWS`, `K-HEADS`, `K-LOCAL`, `K-TARGET` are all allotted at **1/3 their intended size** — 64/8/8/8 bytes instead of 192/24/24/24 (confirmed via ALLOT trace: `ALLOT n=64 here 0xc58 -> 0xc98`, versus the correct `ALLOT n=192 here 0xc58 -> 0xd18` seen in clean runs). `HERE` therefore advances far less than it should. The colon words compiled immediately afterward — `K-SLOT`, `K-PUSH`, `K-LOCAL@` — have their threaded bodies written into memory that *should* have been reserved as array space. Nothing is wrong yet; the words execute fine if called right now.
|
||
|
||
2. **Phase 2 — TRIPOD-TEST, ~173 real seconds later.** `K-INIT` runs again (`fleet-k.4th` block 4405 defines it to run once at capsule-load time *and* TRIPOD-TEST calls it again explicitly). By now all three VMs are long since born, so **any** resolution of `VM-COUNT` — primitive or constant — correctly returns 3. `K-INIT`'s `K-WINDOWS VM-COUNT K-WINDOW-DEPTH * CELLS 0 FILL` now zeroes the **correct** 192 bytes from `0xc58` (confirmed via FILL-TRAP: `addr=0xc58 len=192`) — which, because of Phase 1's under-allotment, reaches straight across `K-SLOT`'s and `K-PUSH`'s already-compiled bodies. The crash addresses (`0xd00`, `0xd08`, `0xd10`) all fall inside this 192-byte zeroed range, past where the 64-byte allotment should have ended.
|
||
|
||
3. **Trigger.** The very next call chain, `CD-TICK → K-BUMP → K-PUSH`, executes the freshly zeroed cells → `NULL cell in 'K-PUSH' after '(start)'`.
|
||
|
||
Every observed artifact is explained by this mechanism: the exact crash address, the three consecutive zero cells (a bulk `memset`, not a partial compile), the ~173-second delay, the FILL/ALLOT trace values, and the run-to-run intermittency.
|
||
|
||
---
|
||
|
||
## The fix
|
||
|
||
**Principle:** dictionary resolution must be arbitrated by definition age everywhere a name lookup can occur — not first-match, not heat order. No FORTH or capsule changes; both `VM-COUNT` entries remain exactly as they are. The constant now always shadows the primitive, per FORTH-79, regardless of what the heat reorg does to bucket order.
|
||
|
||
### New resolver
|
||
|
||
`vm_dict_resolve_in_bucket()` — new function, `src/dictionary_management.c`, declared in `include/vm.h`:
|
||
|
||
```c
|
||
DictEntry* vm_dict_resolve_in_bucket(VM* vm, DictEntry** bucket, size_t n,
|
||
const char* name, size_t len);
|
||
```
|
||
|
||
Scans the *entire* bucket (not stopping at first match), skips `WORD_HIDDEN`/`WORD_SMUDGED`, and among all same-named visible candidates returns the one that appears first when walking the `vm->latest` link chain — the only reliable age order available, since `word_id`s are recycled (`vm_dictionary_untrack_entry` returns them to a free pool) and bucket array positions are exactly what the heat reorg shuffles.
|
||
|
||
### Every lookup path now goes through it
|
||
|
||
- **`hotwords_cache_lookup()`** (`physics_hotwords_cache.c`) — its Stage-2 bucket fallback (the actual primary resolution engine for most lookups in practice) now calls the resolver and only promotes the arbitrated winner into the cache. Its Stage-1 ring scan also gained `WORD_HIDDEN`/`WORD_SMUDGED` checks it previously lacked — a smudged, still-being-compiled definition could previously be served mid-compile.
|
||
- **`vm_find_word()`** (`dictionary_management.c`) — naive fallback scan replaced by a call to the resolver.
|
||
- **`dict_find_word_heat_aware()`** (`dictionary_heat_optimization.c`) — the three-tier heat-percentile scan (25th/50th/75th, first-match-by-heat — the most direct instance of the unsound assumption) now delegates entirely to the resolver. The diversity-driven strategy switch between naive/heat-aware lookup (`vm->lookup_strategy`) is unchanged; a heat-stratified fast path can be layered back on top of the resolver later if lookup latency ever warrants it.
|
||
|
||
### Cache coherence
|
||
|
||
Two new functions, `hotwords_cache_evict_name()` / `hotwords_cache_evict_entry()`, hooked at every event that changes what a name resolves to:
|
||
|
||
- `vm_create_word()` — a new definition may shadow an older same-named word the cache is still serving.
|
||
- `vm_exit_compile_mode()` — the unsmudge on `;` makes a definition visible for the first time. Hooked in **both** implementations (`src/vm.c` and the kernel's `src/starkernel/vm/vm_core.c` — the kernel build excludes `src/vm.c` entirely, so both had to be patched independently).
|
||
- `vm_smudge_word()` / `vm_hide_word()` — visibility changes in either direction.
|
||
- `vm_dictionary_untrack_entry()` — called by `FORGET` before freeing a `DictEntry`. This closes a **latent use-after-free**: the hot-words cache ring previously had no eviction hook at all, so a `FORGET`ed word's freed memory could still be sitting in a cache slot, returned by a later lookup.
|
||
|
||
### API signature change
|
||
|
||
`hotwords_cache_lookup()` now takes `VM*` as its first parameter (needed to walk `vm->latest` for arbitration). Single call site updated (`vm_find_word()`).
|
||
|
||
### Files touched
|
||
|
||
| File | Change |
|
||
|---|---|
|
||
| `src/dictionary_management.c` | New `vm_dict_resolve_in_bucket()`; `vm_find_word()` and `vm_create_word()`/`vm_dictionary_untrack_entry()`/`vm_hide_word()`/`vm_smudge_word()` updated |
|
||
| `include/vm.h` | Resolver declaration |
|
||
| `src/physics_hotwords_cache.c` | `hotwords_cache_lookup()` takes `VM*`, delegates Stage-2 to resolver, gains HIDDEN/SMUDGED checks; new evict functions |
|
||
| `include/physics_hotwords_cache.h` | Updated/new declarations |
|
||
| `src/dictionary_heat_optimization.c` | `dict_find_word_heat_aware()` delegates to resolver (three-tier scan removed) |
|
||
| `src/vm.c` | `vm_exit_compile_mode()` — cache-evict hook |
|
||
| `src/starkernel/vm/vm_core.c` | `vm_exit_compile_mode()` (kernel copy) — cache-evict hook |
|
||
|
||
Both hosted (`make`) and kernel (`Makefile.starkernel`) builds compile clean under `-Wall -Werror`.
|
||
|
||
---
|
||
|
||
## Verification
|
||
|
||
### Trap confirmation (pre-cleanup)
|
||
|
||
With traps still armed, riscv64 log `20260704-161828` showed, during fleet-k.4th's load:
|
||
- `VMC-EXEC` firing on every `VM-COUNT` lookup, consistently returning the constant's entry (`edf=3`), never the primitive.
|
||
- `K-WINDOWS` allotted 192 bytes (`ALLOT n=192 here 0xc58 -> 0xd18`) — versus 64 bytes in every prior failing run.
|
||
|
||
### Three-arch acceptance (traps stripped, loader-experiment reverted)
|
||
|
||
First-ever three-arch run with **identical Artemis dictionary hash** across all architectures:
|
||
|
||
| Arch | Dict hash | virtio-blk / persist-read | Fleet K | Hermes | Artemis | Reap | K soak | E2E msg flow |
|
||
|---|---|---|---|---|---|---|---|---|
|
||
| amd64 | `0xff81e587c380af4a` | PASS | PASS | PASS | PASS | PASS | ✓ | PASS |
|
||
| aarch64 | `0xff81e587c380af4a` | PASS | PASS | PASS | PASS | PASS | ✓ | PASS |
|
||
| riscv64 | `0xff81e587c380af4a` | PASS | PASS | PASS | PASS | PASS | ✓ | PASS |
|
||
|
||
No NULL-cell faults, no `CH-SCAN` hangs, no under-allotment, on any architecture. This is the first three-arch acceptance in the project's history with matching dictionary state on every ISA — previously riscv64 always diverged (see `ARTEMIS-BAM-ACCEPTANCE-20260703.md` for the unrelated disk-boot-path divergence explanation, and this bug for the timing-dependent one).
|
||
|
||
Logs (xz-compressed, 44–137MB raw → 2–3MB): `logs/20260704-170257/amd64/`, `logs/20260704-170446/aarch64/`, `logs/20260704-170651/riscv64/`.
|
||
|
||
---
|
||
|
||
## Lessons
|
||
|
||
- **A wall-clock-gated background pass that reorders any shared structure is a correctness hazard, not just a performance concern**, if any other code path depends on that structure's order carrying meaning (here: recency). The heat reorg's own author already knew reordering could race concurrent access (the function holds `vm->dict_lock` for its whole scan, with a TOCTOU recheck) — but the mutex only prevents torn reads/writes; it does nothing about the *logical* invariant (order = recency) that lookup code silently assumed.
|
||
- **First-match-wins is only safe if the scanned collection's order is guaranteed to reflect what "first" is supposed to mean.** Three independent lookup paths (cache fallback, naive scan, heat-aware scan) all made this assumption; all three needed the same fix.
|
||
- **A word_id is not an age proxy.** IDs are recycled through a free-list (`vm_dictionary_acquire_word_id`/`vm_dictionary_untrack_entry`) specifically so the dictionary doesn't grow unboundedly; a lower ID does not mean an older *live* definition.
|
||
- **Diagnosing by symptom before mechanism is expensive.** The first fix attempt (atomic capsule-loader rollback) was built on a plausible but wrong theory and cost real time — including creating a genuine regression (Hermes's `CD-INIT`/`CH-SCAN`) — before instrumentation-driven evidence (not reasoning from the crash message alone) pinned the actual two-DictEntry collision.
|
||
- **`register_word()` calls for the same name across the base and a sub-vocabulary create multiple coexisting entries by design** (`mama_forth_words.c` registers the whole MAMA word set twice deliberately, once per vocabulary context) — worth keeping in mind for any future primitive that a capsule might also want to define as a FORTH word of the same name.
|