Boot Repeatability Progress
Status: 24 local boots clean out of 24 - but CI still reproduces the copy-on-write stress defect on a build containing every fix below, so this number is not the whole picture. See the correction dated 2026-09-02, from a long-standing ~1 in 8.
Six defects fixed. The first three were in the diagnostics built to hunt the failure rather than in the kernel they were watching. The last three came from CI and nightly logs rather than from another local sweep: a copy-on-write fast path deciding on a fact its compare-exchange could not guard, a kernel address handed to ring 3 as AT_BASE, and - the one that explains the rest - a panic that stopped one core instead of the machine.
24/24 is a good number and not a proof. At the rate this measured immediately before (23/24), a clean run of 24 happens about a third of the time by luck alone. What is stronger than the count is that two of the three new fixes are asserted deterministically - a host test for the copy-on-write window, a ring-3 assertion for AT_BASE - and the third turns any future kernel fault from a silence into a named panic. Last review: 2026-09-01
What fails
Two signatures, both intermittent, on an otherwise green build:
- An instruction fetch from a page that is not present, with
cr2equal torip, inside the same page the process was already executing from. Seen insvc-flap, a service whose whole body is a write and an exit - so the page vanished under a running process rather than the program jumping somewhere wrong. The boot gate reports it asdeliberate_ring3_faults=2_expected=1,unexpected_cpu_fault. - A wedge, at varying phases, reported as
missing:CLI_READYafter 45 seconds of silence.
Why it is filed separately
It was found while trying to certify phase P2 of the memory-manager rewrite, and for a day it was assumed to be that phase's debt. It is not, and the evidence is unambiguous in two independent directions.
Locally, the same 24-boot measurement was taken at three revisions:
| revision | what it is | clean |
|---|---|---|
f45ab1d | the commit before P2 started | 22/24 |
a714dbe | P2 step 2 | 22/24 |
6510827 | P2 complete | 21-22/24 |
In CI, the nightly Boot Smoke x5 (flakiness gate) job - five boots, all of
which must pass, which is this same criterion in miniature - has failed 27 times
out of 31 since the workflow was created on 2026-08-02, including nineteen
consecutive nights on 19ebeb74, a commit that predates any of this work.
So the failure is older than the subsystem it was being blamed on, and older than the gate that reports it.
What it is not
Not the premature-free family. Across these runs the free-while-mapped detector
is silent, the stress service reports no defect, and frames_leaked,
frames_double_put and poison_hits are all zero. Those were the symptoms of
the three concurrency defects fixed during P2 (e02d9dd, 6510827), and they
are gone: the boot rate went from 27/48 while those were live back to the ~90%
that every revision measured before them.
What this cost, and the lesson
Phase P2's completion criterion was written as "48 boots with no failure". With a background failure rate near 8% per boot, the probability of 48 consecutive clean boots is about 0.02% - so that criterion could never have been met, by this revision or by any revision in the project's history. It was measuring the background, not the phase.
Two days were spent treating an unreachable number as a verdict on the work in front of it. The rule worth keeping: a criterion has to be checked against the baseline before it is used to judge a change. One measurement of the parent commit would have said so immediately, and it was not taken until somebody asked for it.
The number was not wasted, though, and that is the other half of the lesson. Insisting on 48 boots surfaced three genuine concurrency defects that a 16-boot gate would have passed over. The mistake was in what the number was allowed to conclude, not in running it.
What the walk dump found (2026-08-31)
A temporary probe printed the four entries of the page-table walk on any fatal not-present user fault. It answered the question the trap dump cannot:
va=0x8000001243 cr3=0x231f000 pml4e=0x040326e0 pdpte=0 pde=0 pte=0
stopped_at_level=1
The leaf is not missing - PML4 slot 1 is, so the whole user window of a
running process is gone. And the value sitting in that slot is not anything this
code writes: the present bit is clear and bit 7 (PS) is set, which is illegal at
that level. Read as data rather than as an entry, 0x040326e0 is a pointer
into the kernel image. The same shape appeared at three different cr3 values
across boots (0x040326e0, 0x040336c0, 0x040336f0).
So a process page table is being freed and handed to some kernel allocation that writes a pointer into it, while a task still runs on that CR3.
This also explains why every memory detector stayed silent through the hunt: they watch frames mapped as leaves, and a page table is not a leaf. The free-while-mapped check could not have caught this by construction.
One candidate was fixed and was not it. execve destroyed the
outgoing address space unconditionally, while hw_task_exit has asked
hw_aspace_still_shared since the wedge it was written for - so a
threaded process that execs freed tables its siblings were still running on.
That is a real defect and the fix is in (hw_aspace_shared_by_other,
asked by address space so exec and exit cannot answer differently), together
with a leak in
fork's error paths, which published a task slot as free without destroying the
address space it had already created. Neither closed this signature.
What it actually was (2026-08-31)
Three defects, found in one afternoon by reading failure logs instead of re-running boots. Every one of them was in the instrumentation.
1. The "who freed it" tag was a use-after-free. hw_free_page_why released
a frame and then wrote the freeing function's name into word 1 of the page.
Between the release and that store another core can allocate the frame - and
word 1 of a page is slot 1 of a PML4, the user window. A diagnostic meant to
say who let go of a page was reaching into a live address space and replacing
its entire user half with a pointer to a string literal.
That is the signature recorded above and never explained: a ring-3 instruction
fetch faulting inside the page the program was already executing from, the walk
stopping at level one, a kernel pointer where a page-directory pointer belonged.
The dump that finally caught it printed the missing half - cr3_state=page-table,
cr3_owners=1: the frame was not free at all. A live, owned PML4 with
garbage in one slot.
The comment that had justified the write is worth keeping in mind. It reasoned carefully about the poison check never probing word 1, and not at all about the frame being reallocated in between. Being careful about the wrong hazard reads exactly like being careful.
2. The free-while-mapped walk was panicking the kernel. It reads every live task's page tables without the scheduler lock - deliberately, because it runs on the frame layer's release path - so it can read a table another core has just freed. A freed frame handed out again holds arbitrary bytes, some with the present bit set and an address field pointing anywhere. Following one faulted the machine, twice in twenty-four boots, and those failures were being counted as the defect it was hunting. Every step is bounded now.
3. The region pool had no lock. Eight refused inserts in a boot whose peak
usage was twenty-nine descriptors out of two thousand - a pool nowhere near full
that had shredded its own free list. Two allocations racing both take the head
and both advance it. fork then failed with ENOMEM and the stress service
reported "fork for cow". The same mistake the frame layer had already made and
fixed, repeated in a layer written the day before.
What remains
One wedge in twenty-four boots, and it has a lead rather than a mystery:
#GP at vibeos_x86_64_task_enter (isr.S:294)
then #GP at rip=0xe4e4e4e4e4e4e4e4
A task's saved register context contains a repeated fill byte, so restoring it
faults - and the panic handler then runs on the broken state and faults again.
0xe4 appears nowhere in the source as a constant, so the next question is
what writes it: an uninitialised context, a recycled slot scheduled before its
creator finished filling it in, or a kernel stack being used after it was freed.
The task state machine's SETUP state and its tenancy counter exist for
exactly this shape and should be the first things consulted.
The remaining wedge was virtio-net transmitting without a lock (2026-09-01)
Named by the wedge report rather than guessed at, which is what that tool is
for. A boot that went quiet at busybox_cat left this:
CPU#0 rip=... vibeos_x86_64_virtio_net_send virtio_net.c:276
CPU#2 rip=... hw_spin_lock <- from hw_sys_munmap
CPU#3 idle
and QEMU said the rest on its own stderr:
qemu-system-x86_64: Guest says index 65535 is available
virtio_net.c had no lock on the transmit path. Every send uses one
staging buffer, one descriptor - g_tx.desc[0] - and one
g_tx.last_used, and publishes with a plain g_tx.avail->idx++
on a 16-bit field.
This is the same defect virtio-blk had, in the same shape, never applied
here. Two cores sending at once do not race over a window, they overwrite each
other: one core's frame lands in the other's descriptor, the available index
skips or repeats - 65535 is what a lost increment on a uint16_t
produces - and whichever core reads the used index first leaves the other
spinning on a completion that has already been consumed. The spin has a bound,
but 50 million pauses is far longer than the gate's quiet budget, so it presents
as a wedge rather than as the timeout it eventually becomes.
Interrupts stay on, as in the block driver: nothing in an interrupt handler transmits, so this lock can never be wanted from one. The timeout path releases it before returning, because holding it there would turn one late frame into a permanently dead network.
Fifth layer in this project to have shipped without a lock, after the frame allocator, the region pool, the page cache and the block driver.
Worth separating from it: the crash record that appears in every boot is
svc-crash dereferencing null on purpose, to prove a ring-3 fault
kills the task and not the machine. It is a gate, not a defect, and its absence
would be the failure.
The copy-on-write failure is a copy that was replaced (2026-09-03)
Deduced from four CI logs, without a new run, and it narrows the search from three causes to one.
The child always reads exactly the parent's value, never garbage:
found 0xd7 expected 0x28 with
after = 0x28 means before = 0xd7. Four logs, four
times, the same relationship.
And op_cow checks the parent's page separately, after reaping the
child - "the child's writes reached the parent". That check has never fired.
Put together: the parent's page is intact, so the child was not writing into it, so the child did have a private frame. And the private frame holds a clean copy of the original, so the child's writes are gone from it.
That is not "the copy never happened". It is "the copy was made and then replaced." One of the three causes, chosen by evidence already in hand.
What that implicates: only clone_one - fork - sets the
copy-on-write bit, and the child of op_cow never forks. So something
is putting that bit back on a page that had already been made private, and the
next fault copies the original over the child's work.
vibeos_pageinfo answers this directly: svc-stress now samples the
frame before the fork, after it, after the child's write and at the check, and
prints which of the three cases it was. That output needs a push to reach
CI - the artifacts analysed here predate it.
The 0xe4 fault is not attributed to anything (2026-09-02)
Nothing in this file explains it, and three attempts to say otherwise were wrong. Recorded plainly so the next attempt does not start from a conclusion.
rip=0x57da77 cr2=0xe4 err=0x5 (user read, present, supervisor-only)
What is known:
- It appears in two different programs,
BUSYBOX.ELFandTHREADS.ELF, at the same rip. Both are static musl binaries, so that address is almost certainly a musl internal function rather than program code - which is why the same number turns up in unrelated programs. - The faulting access is a read of a near-null pointer plus 0xe4. So a pointer that should have been valid came back as zero, or nearly.
- It is deterministic in its path - the same rip, the same offset, every time - and rare in occurrence, a few times in twenty-four boots.
- It appears with the X-P2 cache mapping on and off.
What is not known: anything about the cause.
The three wrong conclusions, kept because the pattern is the lesson:
- "The signature is gone" - from grepping the rip in a boot that had wedged and had no crash record at all, so the rip could not have appeared.
- "The cache mapping causes it" - from 21/24 twice against a baseline reported as better than it was.
- "Turning the mapping off removes it" - from one clean run of twelve, against a defect that appears a few times in twenty-four.
Every one of them read an absence over too short a run as proof. The next attempt needs the faulting instruction disassembled out of the binary the task was running, not another ratio.
A panic stopped a core, not the machine (2026-09-01)
This is the explanation for the silent-wedge family, and it had been visible in every log all along.
hw_panic ended with for (;;) { cli; hlt; } - which stops the
calling core. Its own message said so: "halting on cpu 2". For weeks that line
was read as though it said "halting".
The other three cores carried on. The log kept moving. The machine went quiet some seconds later, at a place with no connection to the fault, and every investigation started from that place. That is why so many of them ended at a plausible-looking pointer with no mechanism behind it: the evidence and the failure were separated by however long it took the survivors to need the core that had died.
A nightly log showed it plainly once the question was asked: a ring-0 #GP on
cpu 2 with action=PANIC, followed by four hundred more lines of healthy
boot, then silence.
The fix. A panic sets a flag and every core parks itself on its next interrupt. Deliberately not an IPI: every core already takes a timer interrupt a hundred times a second, so this needs no new vector, no acknowledgement protocol and no timeout to get wrong. A core inside a syscall with interrupts masked parks when it returns to ring 3; a core that never returns was stuck either way.
Proved by causing one. cpu 3 panics, and cpus 1, 2 and 3 report parking.
The gate now calls it a panic, not a wedge, and carries the reason:
reason=missing:<why> (waiting for CLI_READY) verdict=guest_panicked
Calling a panic a wedge sent the next person looking for a hang. That mattered much more than it sounds, for exactly as long as a panic left three cores running.
A kernel address handed to ring 3 as AT_BASE (2026-09-01)
Found from the nightly's artifacts, which carry the kernel ELF and the guest binaries - so a faulting address could be symbolised against the binary the task was actually running, which is the rule this file has been repeating without being able to follow it.
PIE.ELF faulted at 0x4046220 in _start_c (rcrt1.c:139),
musl's self-relocation for a static position-independent binary. nm on the
kernel places that address inside g_kernel_log.
p->interp_base was written in exactly one place - the branch that maps an
interpreter - and read unconditionally when the startup block was built. A
program without an interpreter therefore shipped whatever was already in that
field to ring 3 as AT_BASE: uninitialised kernel stack for an
execve (hw_proc_t np is a local), or the previous tenant's value
for a recycled task slot. A static PIE relocates itself against AT_BASE,
so musl took a stray kernel pointer as its load address and dereferenced it.
Intermittent for the honest reason that it depends on what was left on the stack - which is why it read as "position_independent_binary_did_not_run" some nights and nothing at all on others. It is also a kernel address disclosure to ring 3 whatever the program does with it.
Zeroed in hw_proc_create, which owns the contract - "every caller must
remember to clear a field" holds until somebody adds a caller. The ring-3 ABI
self-test now asserts AT_BASE is absent for a program with no
interpreter, every boot, deterministically.
The copy-on-write defect: one window closed, the defect still open (2026-09-02)
Correction. This section previously said "found and closed". It was not.
A nightly on a build that contains the fix - its exec line carries
cache_audit_checked, which only exists from d9c0049 -
failed again with the same signature:
STRESS_FAIL: the child's own copy-on-write page at offset 0: found 0x07 expected 0xf8
after is 0xf8, so before is 0x07: the child read the
parent's value after writing its own across the whole page. And
COW_STATS reported exclusive_lost=0, so the window fixed
below was never even entered in that boot.
The window was real - the host test proves it deterministically, and it stays - but it was not this one.
"Closed" was inferred from 24 boots with no stress failure. That is an inference from an absence, on a defect this same file records as appearing about once in twenty-four. This document exists largely to record what that habit costs, and it happened again here.
What the evidence says now, across three occurrences: the child writes
after to all 4096 bytes and then reads before back at
offset 0. That is not a lost write - it is the page being replaced by a fresh
copy of the original after the child had already written into it. So the
question for the next attempt is not "which write was lost" but what resolves
a fault on that page a second time, and how the entry still looks
copy-on-write when it does.
Replay seeds recorded: 76419299086, 97300336535.
The window that was closed (2026-09-01)
Closed by CI logs, not by another boot sweep. The nightly's clang/Release job had failed with
STRESS_FAIL: the child's own copy-on-write page at offset 0: found 0xf3 expected 0x0c
STRESS_FAIL: replay with EFI/BOOT/SVC_STRS.ELF 5498867...
on a build that predates all of this session's work, which settled that it was
pre-existing rather than a regression. Decoding the two numbers is what pointed
at the mechanism: the stress service writes after to every byte of the
page and reads it back, and found=0xf3 is exactly before - the
parent's value. The child was reading the parent's frame after writing its
own.
Two defects, one page of code
1. The fault handler's exclusivity check rests on a fact its
compare-exchange cannot guard. vibeos_vmspace_fault has a fast path:
if the frame has one owner, take the write permission back in place rather than
copying. It reads vibeos_frame_owners(phys), then compare-exchanges the
page-table entry.
The exchange guards the entry. The decision depends on the reference count. The entry does not encode the count, so the two are unrelated, and a fork on another core can take a reference in the window while leaving the entry byte for byte identical.
2. clone_one is what walks into that window. Its already-copy-on-write
branch does no compare-exchange at all - it has nothing to change, since the
entry is already marked - so it takes a reference on the frame and maps it into
the child without touching the source entry. There is nothing for the fault
handler's exchange to notice. It also read the entry with a plain load, in a
file whose entire design is that every page-table word is read once and acted on
atomically.
The result is a process holding a writable mapping of a frame another
address space holds copy-on-write: one side's writes landing in the other's
private page. When the frame is later reused, the same defect shows up instead
as a page holding a value from a completely different round - which is the local
failure, found 0x5b, a before value from another iteration.
The fix, and why it can stay fast
The fast path keeps its optimisation and re-checks after the store: if the frame
gained an owner while the entry was being widened, the entry is put back and the
copy path taken instead. Undoing is safe precisely because no TLB has seen the
writable form - it is installed and withdrawn before any invlpg, and the
faulting instruction has not been retried. clone_one now reads its entry
atomically. cow_exclusive_lost counts the window being hit, because it
was silently common and must never become unobservable again.
It is asserted deterministically, not through boots
This is the part worth keeping. A race that appears once in some number of boots cannot be gated by a boot, and every earlier claim in this file that such a thing was "fixed" rested on a handful of green runs.
vibeos_vmspace_set_race_hook is a seam that lets a host test occupy the
window on purpose: it fires between the ownership decision and the store, and
the test takes exactly the reference clone_one would. The assertion is
that the frame shared during the fault is not the frame the address space can
afterwards write. Removing the re-check turns it red with
FAIL:a frame shared during the fault was made writable in place
every time, on the host, in under a second.
Rate after the fix: 23/24, with no stress failure in any of them.
Superseded: the copy-on-write path (2026-08-31)
Separate from the two signatures above, and the more tractable of everything here because it has a detector that names it:
[MM] FREE_WHILE_MAPPED frame=0x237d000 still mapped by pid=0x5a
during cow-fault mappers=0x2 owners=0x1
Two address spaces hold the frame and one reference is counted, so a get was
lost rather than a put duplicated. Three concurrency defects in this path were
found and fixed during P2 - publication order, release order, and two cores
resolving one fault with a compare-exchange - and the rate improved from 27/48
to the background. This one is not closed. It appears roughly once in
twenty-four boots, and it was reported as fixed once already on the strength of
a clean 48-boot run, which at this rate proves little.
The detector is trustworthy now: it compares mappings against references after the release, so it is indifferent to a frame being reallocated under it - the two predicates it had before were wrong in opposite directions.
Next
- Establish when this started. The nightly has never been reliably green, so the
search goes back before
2026-08-02;scripts/dev/bisect-boot.shtakes a revision and a count and always restores the tree. - The
svc-flapsignature is the more tractable of the two: a page disappearing under a running process is a narrow claim, and the crash records (crashon the kernel console) already keep the registers and the executable name at the moment of the fault. repeat-boot.shkeeps the serial log of every failed boot, so a run leaves evidence rather than a count.
A second intermittent family, found on 2026-09-11: the kernel runs garbage during THREADS
Recorded apart from the signatures above because it is not one of them, and mixing two intermittent failures into one rate is how this file once spent a day on the wrong defect.
What the failing boot showed
Boot 7 of a twelve-boot series, reason=missing:unrecoverable. Read from the
kept log rather than counted:
- A kernel-mode trap on cpu 2 with a frame that is not a frame:
rip=0xffffffff cs=0, andrsp/ssthat decode as ASCII -TMP.andES.TXT, file names from the boot's own self-test script. The core took an exception on a kernel stack holding the contents of a file-name buffer. - A second trap executing at
rip=0x3030303030303030: the string00000000. A return address overwritten with text. - Three cores on
THREADS.ELF, one address space.THREADS_STAGE1_OKprinted,THREADS_OKnot - so it died in the stage where four workers contend a mutex and exit, and the last lines before the panic aremunmapreleasing their thread stacks. - The ring-3 fault at
rip=0x800000016bearlier in the same log issvc-crashfaulting on purpose. It is in every boot, green ones included, and is not the cause. It was mistaken for one once already today.
Why it is recorded as pre-existing
argv-hunt/serial-9.log, dated 2026-09-08 - three days before the process-state
change and everything after it - has the same shape: a kernel-mode fault
executing a garbage address (rip=0x44), three cores on THREADS.ELF sharing
one cr3, THREADS_STAGE1_OK reached and THREADS_OK not. The stage it dies in
exercises neither wait4 nor tkill, which were the change under test.
What is not known
The mechanism. The shape - a kernel stack whose contents became file data, in a
stage full of thread exits and stack unmaps - is the shape of a kernel stack
page reused while still in use, which is the family dead_kstack_base closed
once already. That is a direction to instrument, not a finding. Rate: one in
twelve on this series; the three-day-old log says it was there before, not how
often.
A user-side sign, found later the same day
The twelve boots after the futex change failed twice, and both logs carry a line the first reading passed over, a user write the fault handler refused just before the trouble starts:
COW_FAULT va=0x406d10 rip=0x405982 err=0x7 NOT-handled (THREADS.ELF)
Boot 9 stopped there - the thread was killed, THREADS_OK still printed, and
the boot ended missing:CLI_READY after a POISON_BROKEN report. Boot 1 went on
to the kernel garbage above. fail-7.log, from before the futex change, has the
same line at va=0x4069f0 rip=0x405662: both addresses exactly 0x320 lower,
the size of the stage added in between. One instruction, three failures.
Resolved against the binary that ran (scripts/dev/.resolve-threads.sh):
ripis musl'sstartinpthread_create,lock cmpxchg %edx,0x10(%rdi)- the new thread's first touch of the argument block its creator placed on the new stack. Sordiwas0x406d00.0x406d00is inside__clone: the instruction aftercall *%r9.__clonehands the childrdiwithpop %rdioff the new stack top.
So the child popped a return address - one pushed by a thread that had already started on that same stack and called its start function. When this thread began, the frame at its stack top was not the block its creator wrote but one another thread had left there.
That is a finding about the user side and a direction for the kernel side, not
yet a mechanism: a thread stack mapped over memory still in use (an mmap range
handed out twice, or a physical frame behind it reclaimed early - the
POISON_BROKEN line in boot 9 points at the second) would produce it. What it
does establish is that the kernel stack garbage is downstream: the first thing
to go wrong is visible in ring 3, one instruction into a new thread.
Two probes for the user-side sign, and what they did not find
Both lived in the tree only for the measurement; the second is kept as
.boot-evidence/probe-thread-stack-v2.diff.
- Is a new thread's stack top a frame a live sibling also uses? Recorded at
clone and compared across the thread group. Zero hits. One lesson from the
first run of it: a probe line at WARN makes the gate fail every boot as
kernel_reported_problems- eleven of twelve "failures" in that run were the probe's own lines. Probe at DEBUG or at ERROR only for what should fail. - Is a thread entered from its initial context after it has already run?
Checked in
hw_task_load_cpu_state: rsp and rip still the clone values, and the word at the stack top already the return address__clonepushes. Ten boots (probe-20260911-130736, every log kept): one hit, boot 5, pid 0x55 on its second entry. That thread did not crash and exited 0 - a thread truly restarted there would have taken the return address as its argument and faulted exactly as the signature does. So that load was most likely never returned to, and the mechanism is still not known.ctxis written in only three places: preemption inhw_schedule, and fork and clone.
The family recurred once more in the H-007 series with the same instruction
(0x405b72 in that build, the same start as before) and the same panic.
The exit switch ran with interrupts on (fixed 2026-09-11)
What the probes above were circling. hw_task_exit chooses next, sets it
RUNNING, marks it on_cpu and makes it the core's current task - and then keeps
running the dying task's code for a while: address-space teardown, the
process reference, the locks those take and release. Only after that does it
jump into next.
If a timer interrupt lands in that stretch, hw_schedule sees next as the
current task and does what it does for any preempted task: saves the interrupted
frame as next's context, marks it READY and on_cpu = 0. That frame is the
dying task's, on a kernel stack already parked for release. Another core then
picks next up and resumes the dying task's exit code on that stack, while the
first core's drain frees it. Every piece of the four-worker family fits: "this
task's stack is the free-page poison", kernel frames made of ASCII, a core whose
current task is a slot already reclaimed as SETUP, and - once - a
running -> running transition by hw_task_exit.
The one question was whether interrupts could be on there, since syscall clears
IF. They can: a task killed out of a wait that did sti; hlt reaches the exit
with the flag still set. A probe at the switch counted 4 per boot, every one
a process ended by SIGKILL or exit_group while blocked.
Gated as a mechanism, because the crash cannot be produced on demand: a
must-be-zero counter, exit_switch_irq_on, on the [TASKS] MUSTBEZERO line and
asserted by the gate. Red first - task_exit_switch_irq_on=4 on the unchanged
kernel. The fix is one cli before the choice; nothing below turns interrupts
back on, and the iretq into next restores its own flags. Counter 0,
check.sh all green, twelve boots 12/12.
What is not yet shown: that this was the cause of the four-worker family. That family ran about one boot in eight to ten, so twelve clean boots is consistent with it and proves nothing about it. The counter proves the window is closed and will say so if it reopens; the series from here on will say whether the crashes stopped.
One slip on the way, recorded because the file already warns about it: the
first build of the probe had a syntax error, .c5red.sh printed build-rc=1
and booted anyway, and twelve boots measured the previous kernel. It stops on a
failed build now, and checks that the kernel image is newer than arch_hw.c.
The four-worker family recurred after the exit-window fix (2026-09-11)
The section above said the exit-window fix was not yet shown to end this family.
It did not end it. Boot 7 of the series that verified H-009 (.boot-evidence/fail-20260911-154006-boot7.log)
has the whole signature: THREADS after THREADS_STAGE1_OK, the unhandled write
at rip=0x405b72 in musl's start, then "this task's stack is the free-page
poison" and the machine stopped. exit_switch_irq_on was zero on that kernel.
So the window was a real defect and stays closed, and it was not the cause of this family - or not the only cause. What is still known about the mechanism: a new thread's first instruction finds a return address where its argument should be; no live sibling shares its stack frame; once, an initial context was re-entered without the thread crashing. The family is open again in the review tracker.
The gate that hung for 48 minutes (fixed 2026-09-11)
A boot in a probe run held the whole series for 48 minutes on a guest that had
panicked. The wedge report taken from the still-running emulator had every core
in the panic, fault or serial path. wait_for and the wedge report are both
bounded, which is why the cause took a second reading to find: it was the loop
underneath them.
The serial pump read the socket until recv raised BlockingIOError - until the
guest went quiet. A guest faulting inside its own panic path reprints trap lines
as fast as the port carries them, so the pump never returned, and the deadline
and the silence budget, both checked by its caller, never ran.
drain_available hands chunks on for at most 0.25 s and returns; what is still
waiting is read on the next call. A module-level self-test feeds it a socket that
is never empty with a clock that moves 0.1 s per read, and it must stop after a
few chunks. Validated three ways: the gate compiles, its self-tests pass, and a
copy with the budget check removed hangs at import (killed after ten seconds).
The series that verified it included a crashed boot (.boot-evidence/fail-20260911-162643-boot12.log) that
the gate ended in about a minute.
The probe that hid the defect it was looking for (2026-09-11)
A probe for the four-worker family recorded, at clone, the frame behind each new thread's stack top; counted how often a thread was loaded from its initial context; and printed one line at a probed thread's ring-3 fault saying which of three stories it was - the stack page replaced after clone, the thread started twice, or another thread writing its stack.
It never printed that line, because with it in the kernel the crash did not
happen: 24 boots, then 36 more with a quieter version that logged nothing on the
normal path. Without it, on the same kernel, 36 boots gave two crashes with the
full signature (probe-20260911-174620-boot1 and -boot35: rip=0x405b72,
va=0x406f00). Seventy clean boots at a rate of one in eighteen would happen by
luck about 2% of the time - (17/18)^70.
That is a result rather than a failure. The quiet probe did two things on the path a crash needs: it added 28 bytes to every task, and - when a thread was loaded with its initial context - it walked the page tables to read the word at the stack top. Logging was not the perturbation. Slowing a thread's first start is enough to close the window, which puts the defect there and not in exit or in reclaim.
Code in the kernel cannot observe this without changing it. The next step is to
look from outside: have the gate ask the QEMU monitor for every core's state at
the moment a THREADS fault is reported, the way wedge_report.py already does for
a silent guest.
Sharpened, and why in-kernel probing stopped (2026-09-11)
A probe that runs only at the ring-3 fault - so it cannot touch the window
before it - reproduced the family (four in thirty-six) and printed nothing: the
faulting thread never reaches hw_fault_kill_current_user. Reading the two
traps that arrive together settles what is happening.
- The thread's fault is a write to a text page:
COW_FAULT va=0x406f00 rip=0x405b72, musl'sstartdoinglock cmpxchg %edx,0x10(%rdi)withrdipointing inside__clone(0x406cd1). A new thread's argument pointer is a code address, not its stack - the sign recorded above. - On another core, at the same moment, task 0x8 is entered with a garbage
context:
rip=0xffffffff,cs=0, andrsp/ssthat decode as ASCII (TMP.,ES.TXT) - file-name-buffer bytes. A task's saved registers, or the kernel stack they sit on, were freed and handed out as a file buffer and then scheduled. That is the haltingfree-page poisonpanic.
Both point at the same window: a thread's first schedule. That is exactly where the earlier probe did its one piece of work (a page walk when a task is loaded from its initial context), and slowing it there was enough to make the family vanish for seventy boots - so the defect is in context save/restore around a thread starting, not in exit (the interrupt-window fix, real, did not touch it) or in reclaim.
Why the investigation stops here rather than guessing. Every in-kernel probe
tried changes the timing enough to hide the defect - the family runs about one
boot in twelve to eighteen and disappears under any added work on that path. A
fix written without a confirmed mechanism would be indistinguishable from the
probe: it would make the crash rarer and prove nothing. The next tool is
external: have the gate ask the QEMU monitor for every core's registers and
stack at the instant a THREADS fault is reported, the way wedge_report.py
already does for a silent guest - observation that adds no guest-side work.
Kept apart from the review findings, which are all closed; this one is not.
Observing the four-worker family from outside (2026-09-11)
Since every in-guest probe masks this family, the gate now watches the serial
stream for its marker - free-page poison, or the frame-level POISON_BROKEN,
which appear only when a page was reused while still mapped, and never on a
healthy boot (the null-deref svc-crash fault every boot carries is deliberately
not a trigger). The instant the marker appears, and once per run, it asks the
QEMU monitor for every core's registers and frame walk - the same
wedge_report.py used for a silent guest - and files them in the summary's
wedge_report= field, tagged THREAD-FAULT.
Because the poison panic parks every core, the snapshot is each core essentially
at the fault, not the parked hlt state 45 seconds later that a timeout-driven
report would show. It adds nothing to the guest: the one thing that reliably
changes this family's timing is guest-side work on the thread-load path, and a
monitor read is outside the guest entirely.
thread_fault_signature is a pure function with self-tests, including one that a
detector keyed on the benign fault would trip. Verified: 24 boots through the changed gate were all green (no crash this run), so the snapshot has not yet fired on a real fault; the detector's self-tests are the standing proof, and it captures on the next crash.
Next, when a snapshot is in hand: the faulting thread's registers, and which task each core was running, at the fault - enough to say whether a sibling was mid-context-switch on the freed stack, without a single guest-side instruction.
The four-worker family, found and fixed (2026-09-17)
Closed at last, and the shape of it was not where three sessions of reading had looked. It is not the exit teardown freeing a stack, not the kstack drain, not reclaim. It is a task that runs on a core while its scheduler state says READY.
The reproducer that broke the stalemate. Every in-kernel probe masked this
family because any added work on the thread-load path widened the window shut.
The way past that was not another probe but a reproducer: musl_threads.c
wraps its four-worker create/join round in a loop, THR_4WORKER_REPS (one by
default, so the boot gate is unchanged; built at 30 for the hunt). Repeating the
crashing path faithfully - not adding unrelated work - took the rate from about
one boot in fifteen, and maskable, to two in five. From there the mechanism was
caught in an afternoon instead of chased for a session.
The three detectors, and what each said. A guard in hw_free_kstack_pages
that panics if any core's syscall_kstack_top/rsp0 is inside the range being
freed; a guard in hw_task_release that panics if any core still has the slot
as current_task; and the pre-existing hw_task_load_cpu_state cr3 guard
(address space freed while still schedulable). All three fired on the same
event: a core running a thread whose slot was being released and torn down under
it, consistently ready_by=futex_wake. The clean caller, printed on the
cores-quiesced path in hw_panic_cpu_summary rather than the interleaved raw
one, was hw_task_exit releasing the dying slot while next == dying - the
scheduler had picked the exiting task as the next to run.
The mechanism. A task blocked in hw_futex_wait is BLOCKED and still
on_cpu until its first reschedule. A FUTEX_WAKE in that window sets it READY,
and because it is still on its core it resumes in place - the hlt loop
breaks and it keeps running - without going back through hw_schedule, which is
the only thing that would have set it RUNNING again. So it runs with state
READY. When it then calls hw_task_exit, the exit clears its on_cpu before it
switches away (it keeps executing on its own stack until task_enter), and a
READY, !on_cpu task is exactly what hw_pick_next returns - to this core as
next == dying, or to another core outright. Two cores on one task, one of them
freeing its stack, its address space and its slot. That is every signature this
family ever produced.
The fix. One invariant, reasserted where it was broken: a task running on a
core is RUNNING, never READY. hw_task_exit sets the exiting task RUNNING under
g_sched_lock at entry, so it is never a scheduling candidate while it tears
itself down. Verified with the reproducer: at THR_4WORKER_REPS=30, before the
fix the family hit most boots and the guards fired; after it, 48 boots, zero
crashes, zero guard fires - the guards going silent is mechanism-level proof,
not a ratio. The hw_task_release guard is kept as a permanent gate: it is a
cheap eight-core scan, it never fires on a healthy boot, and this class had just
failed the gcc/Release CI smoke (address space freed while still schedulable,
2026-09-17), so a regression of it should stop the machine with the culprit
named rather than surface as a one-in-fifteen wedge again.
Found in passing, fixed separately: the futex waiter table had a slot-index
ABA of its own (H-007's class). A waiter records its task's slot; hw_futex_wake
woke g_tasks[slot] after only a state == BLOCKED check, so a waiter reaped
and its slot reused could have a wake land on the new tenant. Waiters now record
alloc_seq and a wake requires it to still match. Not the four-worker cause -
that was the READY-while-running invariant above - but a real defect the hunt
surfaced.
Status history
Moved verbatim from the status cell of docs/implementation_progress.md on
2026-09-29, when that table was compacted to one or two sentences per area.
The table says where things stand; this is how they got there.
Boot Repeatability (as of 2026-09-29)
24 boots clean out of 24, from a long-standing 1 in 8. Six defects fixed: three were in the diagnostics rather than the kernel they watched, and three came from CI and nightly logs - a copy-on-write fast path deciding on a fact its compare-exchange could not guard, a kernel address handed to ring 3 as AT_BASE, and a panic that stopped one core instead of the machine, which is what separated every silent wedge from its cause. 24/24 is a good number and not a proof; what is stronger is that two of the three are asserted deterministically and the third turns a silence into a named panic