Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
15 commits
Select commit Hold shift + click to select a range
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
22 changes: 22 additions & 0 deletions issues/audio/gate-a-has-no-runner-baseline.md
Original file line number Diff line number Diff line change
Expand Up @@ -111,3 +111,25 @@ still the dev host's under cross-arch TCG, so this record is unchanged in what
it says and only narrower in where a fresh sample can come from: a hosted
sample is a sample over unnamed CPUs, and a T14 sample is now a job of
`issues/hardware/the-t14-boots-toyos-unattended.md` rather than of a CI lane.

## Main's nightly at 1ce71831 reds on it

Run 36290616312, `audio (2)`: `audio_tone_load.smp1 wake lateness: median
5765 -> 6650 (Mann-Whitney z=4.03 > 3.09)`. Dropouts were 0/60, underruns 0,
ceiling breaches 0/60, and wakes 1396-1426 against the recorded 856-887,
the 1.6x KVM-over-TCG ratio this file records. The same lane on the nightly
before #527 (run 36285169430) read median 6478 with wakes 1394-1425 and
passed. On `nightly-green2` at dbf4ace5 (run 36292135439) it passed too. The
fresh samples agree with each other and differ from the dev host's TCG
sample, so this is the instrument, as above. Until a per-host baseline
exists, whether a KVM runner's gate A reds depends on where its median lands
against the TCG sample's.

The four `audio (2)` samples of `audio_tone_load.smp1` around #527 have
medians of 6453 (before #527, passed), 6648 (main at 1ce71831, red), 6190
(`nightly-green2` at dbf4ace5, passed) and 6520 (`nightly-green2` at
c2715880, red, run 36297455432). Mann-Whitney of each later sample against
the one before #527, on the gate's 30-value arrays: z=1.40, -1.20 and 0.84.
None is a difference at the gate's alpha. The runner's sample did not move.
The gate's verdict flips because that sample's median sits about 0.8 ms above
the TCG sample's 5765, right at the gate's edge.
Original file line number Diff line number Diff line change
@@ -0,0 +1,44 @@
---
status: open
kind: defect
opened: 2026-09-27
---

# `lan_swap`'s redial spent its ceiling on a nightly shard

PR #535's nightly (run 36314576406, `guest (1)`, a4f68c5a, KVM, QEMU 11.1.0):

```
FAIL lan_swap: 2 finding(s):
init's words on netd were ["accepted"] ending in None, where InService is owed (the stream had 1 connection(s) before the ask and 1 after)
the stream's redial was turned away 64 time(s), its ceiling of 64, and gave up
```

The guest completed the swap. Its console has `init: swap netd: in service`
at 6.141 s, and `logd: serving this boot's log on port 41337` at 1.176 s
through the new netd. After that `logd` admitted no reader: no second
`serving this boot's log to 10.0.2.2:…` line. So none of the host's 64 dials
reached `logd` once it listened again. That is consistent with all of them
ending inside the guest's gap, which runs from `logd`'s `netd is being
replaced` (1.000 s), through init stopping the old netd (1.080 s), to `logd`
listening again (1.176 s). The alone re-run was green with 4 dials turned away.

This is `issues/build/swap-crash-rolls-back-reds-when-its-redial-spends-its-ceiling-under-load.md`
on the 82574 bench: the compromise
`issues/diagnostics/a-swaps-redial-asks-again-with-no-event-to-wait-on.md`
records, reached. A redial asks again at once, and the ceiling counts dials,
not time. `lan_swap`'s path (`Ssh::swap`, `metalswap::swap`, `Stream::redial`,
`logd`, netd, init) has no change on #535. Main's nightly at 16d2e645 (run
36306830048) was green. Main's nightly at 1ce71831 (run 36290616312) had the
same two findings on `swap_crash_rolls_back`.

Dev host, QEMU 11.1.1, TCG, one named run each: `nightly-green2` at 877b8c95,
`EXIT=0`, 12 dials turned away; `main` at 16d2e645, `EXIT=0`, 11. Not measured:
how fast a KVM guest turns a dial away, and so how many dials fit inside the
gap there.

`cargo run -- --known-red lan_swap` answers NO.

**Exit**: the redial waits on a guest-side event (the diagnostics issue's exit).
Until then `lan_swap` reds on the nightly at a rate. It should go on #542's
disabled list when that lands, citing this file.
Original file line number Diff line number Diff line change
@@ -0,0 +1,24 @@
---
status: open
kind: finding
opened: 2026-09-27
---

# `swap_crash_rolls_back`'s redial was turned away to its ceiling once on main's nightly

Main's nightly at 1ce71831 (run 36290616312), one guest shard, wide:

```
FAIL swap_crash_rolls_back: 2 finding(s):
init's words on netd were ["accepted"] ending in None, where Restored is owed (the stream had 1 connection(s) before the ask and 1 after)
the stream's redial was turned away 64 time(s), its ceiling of 64, and gave up
```

`ALONE swap_crash_rolls_back: GREEN` twice. It was not red on the nightly
before #527 (run 36285169430).
`cargo run -- --known-red swap_crash_rolls_back` answers NO.

Not shown: what turned the redial away 64 times, and why.

**Exit**: a cause for a redial turned away to its ceiling on a swap that
rolled back, or a rate with enough runs to call it gone.
6 changes: 6 additions & 0 deletions issues/build/wake-storm-cost-red-under-induced-host-load.md
Original file line number Diff line number Diff line change
Expand Up @@ -55,3 +55,9 @@ on a quiet host and on a loaded one, several runs of each, with the host's load
recorded per run. If the ratio moves with the load, the assertion needs a
denominator that host time cannot inflate — a count of claims rather than a span
of cycles. If it does not, the finding is the kernel's and this is a `defect`.

## Third sighting, main's nightly at 1ce71831

Run 36290616312, one guest shard: `FAIL rs::wake_storm_cost: exit code 101`
wide, then `ALONE wake_storm_cost: GREEN` twice. This is again a hosted
four-core shard running eight-vCPU guests, so an oversubscribed host.
Original file line number Diff line number Diff line change
@@ -0,0 +1,33 @@
---
status: open
kind: defect
opened: 2026-09-27
---

# `logd` flushes the records its own refused flush made, for as long as flushes are refused

`logd` makes the volume durable after every round it wrote a line in. A
flush whose first attempt is budget-refused and then retried commits four
kernel records: the storage driver's `not issued` and `ran out of its
operation budget`, the volume's `the device would not answer in the caller's
own budget`, and `fsync: <path> durable on attempt 2`. Those records are the
next round's lines, so that round flushes again. While every flush's first
attempt is refused, the log never goes quiet. It grows by those four records
per round, rotates, and the boot's own early files are rotated away.

Measured at dbf4ace5 with `fsync-budget-spent` refusing every flush's first
attempt, as it did before this branch. In the 2 s after
`home_budget_refusal_retried`'s guest finished, 220 and 131 `/log` flushes
were retried (two runs, `cargo test --test toyos-build -- --nightly
home_budget_refusal_retried`, TCG on the dev host). In CI (run 36285169430,
KVM) the same storm reached `_0003.log` by 28 s, and neither
`home_budget_refusal_retried` nor `log_flush_retry` saw `===READY===`.

The actuator now refuses once per file, so no test stages this any more. On
hardware the loop needs a device whose every flush overruns its operation
budget. Each round then costs at least that budget, so the loop is slow, but
it never ends while the device stays that slow.

**Exit**: a refused-then-retried flush's own records do not by themselves make
`logd` flush again without end, shown by a boot that refuses every flush's
first attempt and whose log goes quiet.
Original file line number Diff line number Diff line change
@@ -0,0 +1,68 @@
---
status: open
kind: defect
opened: 2026-09-27
---

# A collapsed replug is enumerated only when another port event arrives

A device pulled and pushed back between two looks is torn down
(`Step::Teardown(Gone::Replugged)`), and its slot's Disable Slot completes in a
later `Controller::poll` (`kernel/src/drivers/xhci/mod.rs`). There
`slot_gone`'s `AfterSlot::Teardown` calls `PortState::torn_down`, which leaves
the port `Settled` and not attached with the device still in it. `poll` steps
the ports only when `ports_dirty` is set or a port is `outstanding`. Neither is
true then, so nothing looks at the port again. `PORT_WORK_AT` goes to 0, and
PORTSC's CSC stays set because the teardown step returns ahead of the
acknowledge. QEMU raises no further Port Status Change for that port
(`xhci_port_notify` returns while the bit is set), so the device in the port is
never enumerated. It stays dead until an unrelated event marks the ports dirty.
The next unplug is one such event. On the T14 this is a replugged mouse that
does not come back.

Whether the wake is lost depends on how QEMU's two edge events fall across
polls: `xhci_port_update` clears PORTSC and then notifies, so the detach and
the attach each raise their own event. The wake survives when the attach's
event is drained in the same poll as the completion or later. It is lost when
both events are drained before the completion.

## Evidence

- The PR #535 nightly (run 36314576406, `guest (1)`, a4f68c5a) was red with
`0 slot(s) enabled and never disabled ([]) after 4 replugs`. The first three
collapses re-enumerated 100 ms after their teardown (1.780 → 1.881 s). The
fourth was torn down at 3.586 s, and nothing followed in the 900 ms before
the guest's input ended. `wt/toyos-lld` at a55d62c6, an ancestor of `main`
(run 36287592139, `guest (1)`), was red with the same sentence. Its first
collapse (1.971 s) was enumerated only at 2.674 s, 700 ms later, when the
next cycle's edges arrived.
- The dev host, QEMU 11.1.1, TCG, on `nightly-green2` at 877b8c95. QEMU's
`hw/usb/hcd-xhci.c` is byte-identical at v11.1.0 and v11.1.1. With only a
print of the serial added, every other collapse sits about 700 ms until the
next cycle rescues it: 1.022 → 1.725 s and 2.232 → 2.938 s. The test is
green because the fourth cycle is a rescue. With `self.ports_dirty = true;`
added after `torn_down()` in `AfterSlot::Teardown`, all four collapses are
seen as such and each re-enumerates 100 ms after its teardown
(`4 replugs collapsed inside the debounce (4 seen as such): 5 slot(s)
enabled`).
- The same tree with `CYCLES = 3`: red, `EXIT=1`, `0 slot(s) enabled and never
disabled ([]) after 3 replugs`, red again in the harness's alone re-run.
With the one-line wake added it is green, `EXIT=0`, `3 seen as such`.
- One named run of `xhci_flap` as committed is green on `nightly-green2`
(`EXIT=0`) and on `main` at 16d2e645 (`EXIT=0`).

So the gate as committed passes by parity wherever every collapse loses its
wake. On the dev host it cannot go red. It reds on CI's KVM shards only when
the last collapse is the one that loses it.

`AfterSlot::Again` ends in the same `torn_down()` with no look after it; that
arm was not staged.

## Exit condition

A port torn down with its device still in it is looked at again without
waiting for another event, shown by a gate that goes red on the lost wake on
every host. `xhci_flap` at an odd cycle count is one such gate. An assertion
that every collapsed teardown is enumerated before the next cycle's edges is
another. Until then `xhci_flap` reds on main's nightly at a rate. It should go
on #542's disabled list when that lands, citing this file.
Original file line number Diff line number Diff line change
@@ -0,0 +1,16 @@
---
status: open
kind: finding
opened: 2026-09-27
---

# `i8042_health_cadence` counted three counter lines for two keystrokes once on main's nightly

Main's nightly at 1ce71831 (run 36290616312), one guest shard, wide:
`FAIL i8042_health_cadence: two keystrokes three seconds apart, 3 counter
lines — the report is on a timer rather than on the pin`. `ALONE
i8042_health_cadence: GREEN` twice.
`cargo run -- --known-red i8042_health_cadence` answers NO.

**Exit**: the red run's three counter lines matched to the edges that
produced them, or a rate with enough runs to call it gone.
Original file line number Diff line number Diff line change
Expand Up @@ -23,15 +23,28 @@ The mechanism read off the code: `logd` puts a program's line in
and then a chunk of queued lines per hold of the wire, whatever their age. The
stop stops every userland thread and writes its last word as a record, which
`drain_inline` or `klogd`'s next pass puts on the wire; a line still in the
queue then goes after it, inside `quiesce-late-word`'s window. `main` has no
queue — a holder wrote the wire itself — so this is the branch's.

The likely fix is a drain of the queue on the wire between the stop of every
holder and the last word, where nothing can add to it. No deterministic
stimulus exists yet: the red needs the queue non-empty at the last word, which
only a `klogd` slower than `logd` gives.
queue then goes after it, inside `quiesce-late-word`'s window.

## Exit condition

No holder's line can follow the last word by construction, and a test that
leaves a line in the queue at the stop goes red without that and green with it.

## The stop now drains the queue

The stop drains the queue on the wire right after
`quiesce::stop()`, before `Syncing filesystems...`
(`log::console::drain_for_the_stop`). `console-queue-at-the-stop` is the
deterministic stimulus: it queues one line after every holder is stopped and
keeps `klogd` off the queue from the stop's claim on.
`quiesce_stops_the_machine` arms it and judges the line above the last word.
- The drain disabled as a checked patch: `cargo test --test toyos-build --
--nightly quiesce_stops_the_machine` EXIT=1, `1 line(s) reached the
console after the boot's last word: console: a holder's line, queued once
the stop had stopped every holder`, wide and alone. The power-off's
`serial::flush_final` wrote it.
- With the drain: EXIT=0.

What is left of "by construction" is a stop that did not stop every holder,
which it reports at alert level. A holder that still runs after the drain
can queue a line that follows the last word.
Original file line number Diff line number Diff line change
@@ -0,0 +1,39 @@
---
status: open
kind: defect
opened: 2026-09-27
---

# A log ring's owner is named only when `logd` reads its registration, so a child that floods first takes the owner's slots

`toyos::log::Ring::push` keeps `CHILD_KEEP` shared slots free for the ring's
owner, but only once the owner word is set. `logd` sets it (`origin.rs`,
`ring.own(pid)`) when it reads init's `REGISTER` frame. init sends that
frame after it spawns the program (`userland/init/src/main.rs`, `register`).
Until `logd` reads the frame the owner word is 0, and `push` then keeps
nothing for anyone. A child that starts flooding in that window can take
every slot, the owner's included.

`log_ring_keeps_the_owners_slots` (fast tier) is red this way beside the
other `log_` guests and green alone. Its `/log` holds `===READY===`,
`===TEST_START test_rs_log_flood===` and 1917 flood lines: exactly the ring's
1919 shared slots, with no slot left for test-runner's `===TEST_END`.
`logd: reading test-runner again ... with 1919 of its ring's 1919 records
waiting`.

Rates on the dev host (TCG), `cargo test --test toyos-build -- --nightly
log_`, interleaved per round against `origin/main`'s kernel and tests:
- the branch that filed this, `nightly-green2`: 3 red of 14 (3 of 9 before
its merge of 16d2e645, one of those in a run before the interleaving
began; 0 of 5 after);
- `origin/main`: 2 red of 13 (0 of 8 at 1ce71831, 2 of 5 at 16d2e645).
Each red was this failure. The race is on `main`.

The fix belongs where the owner is decided:
- init names the owner itself, after the spawn and before the frame. That
narrows the window and does not close it.
- Or `Ring::push` treats an unowned ring as one in which every writer leaves
`CHILD_KEEP`, which closes it. That is `toyos/src`, the SDK.

**Exit**: a child writing before the ring's owner is named cannot take the
slots the owner is kept, shown by a test that makes it write in that window.
Original file line number Diff line number Diff line change
@@ -0,0 +1,42 @@
---
status: open
kind: defect
opened: 2026-09-27
---

# `handle_kill_policy`'s census grew by one `SharedMem` on two nightlies in a row

Main's nightly at 16d2e645 (run 36306830048, `guest (8)`) and PR #535's at
a4f68c5a (run 36314576406, `guest (8)`), KVM, QEMU 11.1.0, both red with
byte-identical text, numbers included:

```
16 more killed processes left more live objects behind: [("SharedMem", 9, 10)] — first PipeRead 6, PipeWrite 5, Connection 2, Device 1, Acceptor 5, Inbox 6, SharedMem 9, ...
```

Both had `ALONE handle_kill_policy: GREEN`. It was green on the nightlies at
1ce71831 (run 36290616312) and at c2715880 (run 36297455432). c2715880 already
carries 16d2e645, so this is a rate on `main`'s code. The actuator boot it
shares carried the same eight tests in all four runs, and test-runner runs
one job at a time.

Dev host, QEMU 11.1.1, TCG, one named run each: `nightly-green2` at 877b8c95,
`EXIT=0`; `main` at 16d2e645, `EXIT=0`.

What is known: every holder the test kills holds one `SharedMem` region and
one pipe, and `settled_census` answers once two readings 10 ms apart agree.
The mechanism
`issues/kernel/deferred-release-outlives-its-syscall.md` records is a release
still in flight on another CPU when both readings are taken. That would read
exactly like this: one killed holder's region is not yet released at the
second census. The red boot's kernel reports a TLB shootdown wait of up to
13667 us (`tlb: … max=13667us`), longer than the settle's 10 ms.
Not shown: which process held the tenth `SharedMem`, or that its release was
the one in flight.

`cargo run -- --known-red handle_kill_policy` answers NO.

**Exit**: the census names the owner of a grown kind, and the red is
attributed or the release is shown to finish before `wait` returns. Until then
`handle_kill_policy` reds on main's nightly at a rate. It should go on #542's
disabled list when that lands, citing this file.
Original file line number Diff line number Diff line change
@@ -0,0 +1,32 @@
---
status: open
kind: defect
opened: 2026-09-27
---

# A panic in the storage phase reads its key off an i8042 the kernel has not configured

The panic panel's reset bound is retired by a key press
(`kernel/src/drivers/panic_console/mod.rs`, `read_key`), which polls port
`0x60` through `keyboard_controller::poll_byte`. `i8042::init`
(`kernel/src/arch/x86_64/i8042/mod.rs`) is what turns translation on, stops
and restarts scanning and enables the port-1 clock. It now runs first in the
device phase (`arch::boot::platform_devices` in `kernel/src/main.rs`), after
storage, so its lines stay on a panel that shows the log's tail.

So a panic anywhere in the storage phase — NVMe or xHCI init,
`rootfs::hold_source`, the DATA and FAT mounts — meets the controller as the
firmware left it. Whether a key press then reaches `read_key` as a set-1 make
code depends on the firmware: with translation off or scanning off it does
not, and the panel resets at its bound however many keys are pressed. That
ordering is the one the tree had before storage moved behind init's spawn, so
it has shipped before; it is still a weakness. No boot exercises a panic in
the storage phase with the firmware's controller state left unconfigured.

## Exit condition

A key press retires the panel's bound for a panic anywhere after the i8042
probe could have run — the controller configured before the first phase that
can panic on a device, without moving its lines off the panel's tail — and a
boot that panics in the storage phase on the metal-sim shape shows the press
retiring it.
Loading
Loading