From cbe609c088ad2617b6cde07e7e9e86f5ccf9f3d6 Mon Sep 17 00:00:00 2001 From: japabu Date: Sat, 3 Oct 2026 00:41:47 +0200 Subject: [PATCH 01/11] issues: the T14's 8 to 11 ms window is the log's USB write; its firmware interrupts every CPU every 2.2 s MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit One T14 boot of main at c59e09ed6 with a throwaway instrument (never landed; scout.patch sha256 f5a0208c…ac458a) named what opens every interrupts-off window of 2 ms or more, sampled the CPU holding it, traced each shootdown's acknowledgements and read MSR_SMI_COUNT on every CPU. It ran test_rs_ring_park_herd forty times. Its lines are quoted on the pull request; the scratch readback does not outlive the session. - some-t14-boots-carry-an-interrupts-off-window-of-9-ms-or-more is renamed to what the boot shows and rewritten as present state: the LOG fsd's SYS_PARTITION_WRITE spins in XhciController::wait_transfer with interrupts masked for the whole USB transfer, 8.3 to 10.7 ms on one CPU nine times, and twice while seven herd threads in SYS_THREAD_EXIT spin masked on its shootdown acknowledgement, 7.7 to 7.85 ms. The old title's "some boots" was a sampling artefact of one herd run per boot: the write recurs every 2.0 to 4.6 s. Owners: the small-kernel track and syscall-preemption-is-incidental. The opened date stays, as renames do. - cpu0-holds-interrupts-and-preemption-off-for-6-5-ms-on-the-t14 has its opener: init in SYS_DEVICE_CLAIM, two partition claims reading the stick's table through the same wait and one PCI claim whose single sample is in PciDevice::is_id. The exit's naming half is met and goes. - New: the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos-and- not-under-linux. MSR_SMI_COUNT went 4824 to 4841 on all eight CPUs, each step about 4.5 ms on every CPU; under Linux perf read 0 in 120 s. The cause is not known. - a-process-lengthens-an-interrupts-off-walk…: its citation follows the rename. the-cpu-that-spawns-a-toybox-applet… is unchanged: the instrument printed only windows of 2 ms or more, so this boot says nothing new about it. Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_013UDZQ6fSKw14e4w2TKTRfm --- ...y-2-2-s-under-toyos-and-not-under-linux.md | 52 ++++++++++ ...usb-transfer-on-one-cpu-or-on-all-eight.md | 75 +++++++++++++++ ...alk-by-the-threads-it-parks-on-one-ring.md | 4 +- ...nd-preemption-off-for-6-5-ms-on-the-t14.md | 24 +++-- ...n-interrupts-off-window-of-9-ms-or-more.md | 94 ------------------- 5 files changed, 145 insertions(+), 104 deletions(-) create mode 100644 issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos-and-not-under-linux.md create mode 100644 issues/kernel/a-log-write-to-the-t14s-stick-masks-interrupts-for-its-whole-usb-transfer-on-one-cpu-or-on-all-eight.md delete mode 100644 issues/kernel/some-t14-boots-carry-an-interrupts-off-window-of-9-ms-or-more.md diff --git a/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos-and-not-under-linux.md b/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos-and-not-under-linux.md new file mode 100644 index 00000000000..7ab29e042c6 --- /dev/null +++ b/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos-and-not-under-linux.md @@ -0,0 +1,52 @@ +--- +status: open +kind: defect +opened: 2026-10-03 +--- + +# The T14's firmware interrupts every CPU every 2.2 s under ToyOS, and not under Linux + +On LENOVO 20W0003AMZ, BIOS N34ET71W (1.71), one boot of `main` at `c59e09ed6` +with a throwaway instrument that reads `MSR_SMI_COUNT` (MSR 0x34) on each CPU +as each interrupts-off window opens and closes read the count from 1.20 s to +38.79 s into the boot, `test_rs_ring_park_herd` running forty times in it. Its +lines are quoted on the pull request that landed this text. + +- **It moved 17 times, from 4824 to 4841, on all eight CPUs alike**: at each of + the boot's 42 reports the eight read the same value. +- **About every 2.2 s.** Fifteen of the steps fall inside a window the + instrument printed, and the windows that caught consecutive steps close + 2,215,327,897 to 2,221,576,672 ns apart, median 2,216,534,952. +- **Each step stops every CPU for about 4.5 ms.** The 25 interrupts-off + windows a step falls in read 4,529,514 to 4,764,935 ns: sixteen open in a + job's syscall or interrupt, thirteen of them `SYS_SYSINFO`, and nine in a + pass leaving idle. None of those sections reads 2 ms where no step falls. + Each window has one sample of its CPU, 4.52 to 4.70 ms after it opened, + where a CPU the instrument holds masked on purpose is sampled every 2 ms. At + 9.925 s all eight CPUs carry one at once. Two CPUs waiting on a lock across a + step went 4,503,694 and 4,554,675 ns between two turns of their own spin. +- **Under Linux it does not move.** On the same machine under Ubuntu's + `6.8.0-142-generic`, `perf stat -a -A -e msr/smi/` read 0 on every CPU over + 120.378 s. + +What differs, as far as anything has read: + +- ToyOS performs no ACPI enable handshake: `rg -n -i + 'smi_cmd|acpi_enable|sci_en|smi_en|0xb2\b' kernel/src bootloader/src` finds + only the xHCI legacy handoff's own `USBLEGCTLSTS` enables + (`kernel/src/drivers/xhci/legacy.rs`), and nothing reads `PM1a_CNT.SCI_EN` + or the chipset's `SMI_EN`. Both controllers' `USBLEGCTLSTS` read + `0xe0000000`, no enable set, before the handoff wrote it. +- Under that Linux the orchestrator reports the FADT's `SMI_CMD=0xb2` and + `ACPI_ENABLE=0xf0`, `PM1a_CNT.SCI_EN=1` and `SMI_EN=0x10002033`. The output + of those reads was not kept. +- Under ToyOS neither `SCI_EN` nor `SMI_EN` has been read. + +The cause is not known. The `mask-windows` kernel prints such a window as its +CPU's own: the lines of 4,720,498 and 4,725,822 ns in #649's boots +(`issues/kernel/cpu0-holds-interrupts-and-preemption-off-for-6-5-ms-on-the-t14.md`, +`issues/kernel/a-process-lengthens-an-interrupts-off-walk-by-the-threads-it-parks-on-one-ring.md`) +are this by reading, those kernels not reading the count. + +**Exit**: `MSR_SMI_COUNT` does not move during a boot on the T14, read by a +row. diff --git a/issues/kernel/a-log-write-to-the-t14s-stick-masks-interrupts-for-its-whole-usb-transfer-on-one-cpu-or-on-all-eight.md b/issues/kernel/a-log-write-to-the-t14s-stick-masks-interrupts-for-its-whole-usb-transfer-on-one-cpu-or-on-all-eight.md new file mode 100644 index 00000000000..03685a593a5 --- /dev/null +++ b/issues/kernel/a-log-write-to-the-t14s-stick-masks-interrupts-for-its-whole-usb-transfer-on-one-cpu-or-on-all-eight.md @@ -0,0 +1,75 @@ +--- +status: open +kind: defect +opened: 2026-10-02 +--- + +# A log write to the T14's stick masks interrupts for its whole USB transfer, on one CPU or on all eight + +On LENOVO 20W0003AMZ, BIOS N34ET71W (1.71), `/log` is a FAT32 partition of the +USB stick the machine boots from, and `/system/bin/fsd` in the LOG role writes +it with `SYS_PARTITION_WRITE`, which the kernel's USB mass storage serves. The +kernel waits for the transfer by spinning on the event ring under the +controller's lock (`XhciController::wait_transfer`, +`kernel/src/drivers/xhci/wait/mod.rs`), inside a syscall, which runs with +interrupts masked from entry to exit. So the writing CPU holds interrupts and +preemption off for as long as the stick takes, and a CPU whose shootdown waits +on it waits as long, masked. + +Read in one T14 boot of `main` at `c59e09ed6` with a throwaway instrument that +records every window of 2 ms or more with the addresses that opened and closed +it, its CPU's last events, and samples of that CPU every 2 ms; the boot ran +`test_rs_ring_park_herd` forty times. Its lines are quoted on the pull request +that landed this text. Pid 4 is that fsd. + +- **Eleven writes of 7.8 ms or more in 37 s**, 2.0 to 4.6 s apart, each window + opened at the syscall's entry and closed at its return. Nine are on one CPU + alone: 8,289,211 to 10,669,042 ns. 36 of their 37 samples are in + `wait_transfer < bulk < bot < scsi < transfer_blocks` under `storage_write`; + the 37th is the same syscall waiting for the process table's lock. +- **All eight CPUs at once, twice**, at 17.416 s and 21.116 s: the write on one + CPU (7,848,573 and 7,927,725 ns) while a herd thread on each of the other + seven is in `SYS_THREAD_EXIT`, whose unmap shoots down every CPU's TLB. The + fourteen shootdowns span 7,703,612 to 7,852,515 ns, and their initiators + spin: none goes more than 10,819 ns between two turns of its wait. The other + targets acknowledge within 24 µs; the writing CPU acknowledges by interrupt + once its syscall has returned, 74 to 299 ns before each shootdown ends. Each + event is followed at once by a shorter one of the same shape: the next + write, 2,824,878 and 2,846,782 ns, and fourteen more shootdowns. The + report's `tlb:` line reads `max=7846us` after the first, where it read + `max=1146us` before it. +- **Shorter**: sixteen of the same server's writes read 2,368,371 to + 2,905,716 ns, those two among them, and two of its + `SYS_PARTITION_READ` 2,596,003 and 2,954,780. At the stop, the black box + keeps a write opened at 38.795 s whose CPU's next event comes + 7,953,409 ns later. +- **Not the firmware**: `MSR_SMI_COUNT` does not move across any of them. The + windows it does move across are + `issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos-and-not-under-linux.md`'s. +- **The instrument's control**: a 50,000,024 ns hold reads back as a + 56,000,902 ns window on its CPU, sampled in `kernel::windows::hold_once` + every 2 ms. The excess is the instrument's own report, which that same + `SYS_EXIT` prints (5,918,088 ns): a window on a CPU printing a report + includes the report. + +The `mask-windows` kernel (`kernel/src/windows.rs`) prints a span and no +opener. #649's fourteen T14 boots printed spans that are these writes by +reading, no opener having been recorded: every CPU at once at 9,603,617 to +9,651,846 ns beside `tlb: … max=9575us` (the fourth `mask_windows` boot at +`72f16e39a`) and at 2 × 5,014,552 to 2 × 5,075,290 beside `max=10038us` +(`649-r6/2-report-halved`, comment 5960575031); one CPU alone at 9,260,193 +(the seventh at `72f16e39a`); cpu7, where pid 4 started in both boots, at +11,492,028 and 8,456,658 before the first job's exit (`649-r6/1-head`, +`649-r6/3-idle-halt-counted`); and one CPU at 10,214,820 to 11,645,411 in the +stop's report of five boots. + +The window goes when the kernel stops serving the stick: +`issues/kernel/the-kernel-is-small-interrupts-post-and-threads-wait.md`'s +step 10 moves the xHCI to usbd, and its stage 5 exits on no interrupts-off +window longer than a register access. The waiters are masked because a +syscall is (`issues/kernel/syscall-preemption-is-incidental.md`). + +**Exit**: a T14 boot that writes the log as this one did prints no +interrupts-off window that a USB transfer opens, read by an instrument that +names a window's opener; or this file is replaced by the bound the write is +held to and the derivation of it. diff --git a/issues/kernel/a-process-lengthens-an-interrupts-off-walk-by-the-threads-it-parks-on-one-ring.md b/issues/kernel/a-process-lengthens-an-interrupts-off-walk-by-the-threads-it-parks-on-one-ring.md index e10367acbf8..31f5404bfbf 100644 --- a/issues/kernel/a-process-lengthens-an-interrupts-off-walk-by-the-threads-it-parks-on-one-ring.md +++ b/issues/kernel/a-process-lengthens-an-interrupts-off-walk-by-the-threads-it-parks-on-one-ring.md @@ -57,8 +57,8 @@ mutated kernels) read the same report of the same load at 1980239 969922 to 1044783. - 2 × 5075290 is one of eight: every CPU reads 2 × 5014552 to 2 × 5075290 (`:416` to `:430`), beside `tlb: shootdowns=282 wait=131633us max=10038us` - (`:431`). It is the first reading of - `issues/kernel/some-t14-boots-carry-an-interrupts-off-window-of-9-ms-or-more.md`. + (`:431`). It is the all-CPU shape of + `issues/kernel/a-log-write-to-the-t14s-stick-masks-interrupts-for-its-whole-usb-transfer-on-one-cpu-or-on-all-eight.md`. - 4725822 is cpu0's. The other seven read 544283 to 1018355. So one size reads 1.03 to 10.15 ms over six boots, and which boot carried diff --git a/issues/kernel/cpu0-holds-interrupts-and-preemption-off-for-6-5-ms-on-the-t14.md b/issues/kernel/cpu0-holds-interrupts-and-preemption-off-for-6-5-ms-on-the-t14.md index 19ebc5402e4..2631deba979 100644 --- a/issues/kernel/cpu0-holds-interrupts-and-preemption-off-for-6-5-ms-on-the-t14.md +++ b/issues/kernel/cpu0-holds-interrupts-and-preemption-off-for-6-5-ms-on-the-t14.md @@ -36,13 +36,21 @@ cpu0's line, in the seven boots where no longer window covers it: before init's first line at 1.161 or 1.162 s. The fourth boot's cpu0 reads 9644415 and 9643939, the event -`issues/kernel/some-t14-boots-carry-an-interrupts-off-window-of-9-ms-or-more.md` +`issues/kernel/a-log-write-to-the-t14s-stick-masks-interrupts-for-its-whole-usb-transfer-on-one-cpu-or-on-all-eight.md` records. -Nothing names what opens it. A report carries a span and no address, and one -report a boot cannot say whether the window recurs. What will: the record -keeping, beside each CPU's longest span, the address its opening hook was -called from, printed in the report and resolved through the kernel's symbols. +It is init in `SYS_DEVICE_CLAIM`. One boot of `main` at `c59e09ed6` with a +throwaway instrument that names a window's opener and samples its CPU every +2 ms (its lines quoted on the pull request that landed this text) read cpu0's +line at 6623907 and 6623757 and named that window: pid 0, opened at the +syscall's entry and closed at its return, from 1.179 s, both samples in +`XhciController::wait_transfer` under `storage_read`. Two more of init's +claims precede it on cpu0: one at 1.171 s of 6,002,063 ns, both samples in +`wait_transfer` under `storage_read`, and one at 1.162 s of 3,817,265 ns, +whose one sample is in `PciDevice::is_id` under `pcidev::claim`. By reading, a +partition claim reads its disk's table when asked (`gpt::claimable`, +`kernel/src/gpt.rs`) through the same masked USB wait as that event's. Nothing +has said what the PCI claim spends 3.8 ms on. It opens before the boot's first job ends. The three boots of #649 at `8b73eba69` (comment 5959415453, readbacks `649-r5/1-head`, @@ -53,6 +61,6 @@ boot (`windowscase/kernel.log:348` in each), reads 6533222, 2 × 3273547 and 6508165. In the three reports after it cpu0 reads at most 943904, 2 × 472938 and 345229. -**Exit**: the section that opens the window is named by that reading on the -T14, and cpu0's longest window there no longer includes it, or this file is -replaced by the bound the section is held to and the derivation of it. +**Exit**: on the T14, cpu0's longest window before the first job's exit no +longer includes init's claims, or this file is replaced by the bound they are +held to and the derivation of it. diff --git a/issues/kernel/some-t14-boots-carry-an-interrupts-off-window-of-9-ms-or-more.md b/issues/kernel/some-t14-boots-carry-an-interrupts-off-window-of-9-ms-or-more.md deleted file mode 100644 index 8d70322a2f2..00000000000 --- a/issues/kernel/some-t14-boots-carry-an-interrupts-off-window-of-9-ms-or-more.md +++ /dev/null @@ -1,94 +0,0 @@ ---- -status: open -kind: defect -opened: 2026-10-02 ---- - -# Some T14 boots carry an interrupts-off window of 9 ms or more - -Read by the `mask-windows` kernel (`kernel/src/windows.rs`) on LENOVO -20W0003AMZ, BIOS N34ET71W (1.71), in the eight `mask_windows` boots of #649 -at `72f16e39a`: four as that head stands and four with stage 6 step 1 (#634) -reverted on it, one job each, `test_rs_ring_park_herd`. The longest window -that recurs in every boot is cpu0's 6.5 ms -(`issues/kernel/cpu0-holds-interrupts-and-preemption-off-for-6-5-ms-on-the-t14.md`). -Three readings are longer, each in some boots and not in others, on both -arms: - -- **Every CPU at once, the fourth boot** (step 1 in). The herd's report: - - | CPU | `irqs_off_ns` | `preempt_off_ns` | - |---|---|---| - | cpu0 | 9644415 | 9643939 | - | cpu1 | 9603617 | 9588515 | - | cpu2 | 9627971 | 9625674 | - | cpu3 | 9641999 | 9620791 | - | cpu4 | 9651846 | 9635137 | - | cpu5 | 9623545 | 9612295 | - | cpu6 | 9624969 | 9621345 | - | cpu7 | 9614836 | 9614716 | - - The same report's shootdown line reads - `tlb: shootdowns=280 wait=125911us max=9575us`, where the other seven - boots read at most `wait=49119us` and at most `max=1421us`, and cpu0's - census reads `nmi=2`, where the other seven read `nmi=1`. -- **One CPU, the seventh boot** (step 1 reverted). cpu7 reads 9260193 and - 9260124. cpu0 reads its 6590095, the other six 920,455 to 1,404,001, and - the shootdown line `max=1386us`. -- **One CPU, after the herd's report, in four boots of the eight.** The stop - prints a report too, of which the black box keeps the lines of cpu2 to - cpu7. In it one CPU reads - - | boot | CPU | `irqs_off_ns` | `preempt_off_ns` | - |---|---|---|---| - | 1, reverted | cpu7 | 10677997 | 10677829 | - | 2 | cpu7 | 11267384 | 11267320 | - | 5, reverted | cpu2 | 10214820 | 10214656 | - | 6 | cpu7 | 10874427 | 10874364 | - - and in the other four cpu7 reads 1,424,134 to 1,532,702 ns and no kept - line more. What that report spans is the herd's teardown, which its own - report precedes, the spawn of `reboot` on cpu7 and the stop. - -By reading, not measured: every CPU waiting out one CPU's masked window -inside a shootdown would read as the fourth boot does. - -Nothing names what opens any of them. A report carries a span and no address, -and no time: eight equal spans are not shown to be one event. What will: the -record keeping, beside each CPU's longest span, the address its opening hook -was called from and the counter it closed at, printed in the report. - -The third reading falls on the `reboot` and stop side of the herd's -teardown. The three boots of #649 at `8b73eba69` (comment 5959415453, -readbacks `649-r5/1-head`, `649-r5/2-report-halved`, whose kernel prints half -of every span, and `649-r5/3-idle-halt-counted`) took a report at `echo`'s -exit, after the herd's and before `reboot` was spawned. Its longest -`irqs_off_ns` is cpu7's in each: 1499808, 2 × 748872 and 1479558 -(`windowscase/kernel.log:456`). The stop's report after it, in the six lines -the black box keeps, reads cpu7 11522834 and cpu4 11645411 in the first boot -(`649-r5/1-head/windowscase/loader.log:57`, `:63`), and at most cpu7's -2 × 3799327 in the second and cpu7's 1305656 in the third. - -The three boots at `0aa8d4c88` (comment 5960575031, readbacks -`649-r6/1-head`, `649-r6/2-report-halved` and `649-r6/3-idle-halt-counted`, -the same two mutated kernels) print a report at three exits, `idle_span`'s, -`pwd`'s and the herd's, and at the stop: - -- **The first reading recurred, inside the herd's own report**, which opens - at `pwd`'s exit. In `2-report-halved` every CPU reads 2 × 5014552 to - 2 × 5075290 (`windowscase/kernel.log:416` to `:430`), beside - `tlb: shootdowns=282 wait=131633us max=10038us` (`:431`): the shootdown's - `max` is beside it again, 9575us then and 10038us now, and cpu0's second - NMI is not: `nmi=1` (`:415`). That is two boots of #649's fourteen. -- **One CPU, before the first job's exit.** cpu7's line of the first report, - `idle_span`'s (`:362`), reads 11492028 in `1-head`, 2 × 1308074 in - `2-report-halved` and 8456658 in `3-idle-halt-counted`, beside - `max=1655us`, `max=1451us` and `max=1353us` (`:363`). The same line read - 2327848, 2 × 1831727 and 3630933 at `8b73eba69`. -- **Nothing after the herd's report.** The stop's report, in the six lines - the black box keeps, reads at most cpu7's 1396887, 2 × 758960 and 1470910 - (`windowscase/loader.log:57`). - -**Exit**: each of the three, and the one-CPU reading before the first job's -exit, is named by that reading on the T14, and is removed, or this file is -replaced by the bound it is held to and the derivation of it. From 9a2b98888ea26e452767ef9c2b9f3a57af159ef6 Mon Sep 17 00:00:00 2001 From: japabu Date: Sat, 3 Oct 2026 00:42:26 +0200 Subject: [PATCH 02/11] issues: cite the evidence comments on #681 The three files that rest on the scout boot now name the comments its lines are quoted in: 5962618149 (the boot, its control, the storage windows), 5962618492 and 5962618868 (the two all-CPU events) and 5962619169 (the firmware's interrupt). Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_013UDZQ6fSKw14e4w2TKTRfm --- ...s-every-cpu-every-2-2-s-under-toyos-and-not-under-linux.md | 3 ++- ...s-for-its-whole-usb-transfer-on-one-cpu-or-on-all-eight.md | 4 ++-- ...lds-interrupts-and-preemption-off-for-6-5-ms-on-the-t14.md | 2 +- 3 files changed, 5 insertions(+), 4 deletions(-) diff --git a/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos-and-not-under-linux.md b/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos-and-not-under-linux.md index 7ab29e042c6..277c3282783 100644 --- a/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos-and-not-under-linux.md +++ b/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos-and-not-under-linux.md @@ -10,7 +10,8 @@ On LENOVO 20W0003AMZ, BIOS N34ET71W (1.71), one boot of `main` at `c59e09ed6` with a throwaway instrument that reads `MSR_SMI_COUNT` (MSR 0x34) on each CPU as each interrupts-off window opens and closes read the count from 1.20 s to 38.79 s into the boot, `test_rs_ring_park_herd` running forty times in it. Its -lines are quoted on the pull request that landed this text. +lines are quoted on #681 (comment 5962619169; the boot itself in comment +5962618149). - **It moved 17 times, from 4824 to 4841, on all eight CPUs alike**: at each of the boot's 42 reports the eight read the same value. diff --git a/issues/kernel/a-log-write-to-the-t14s-stick-masks-interrupts-for-its-whole-usb-transfer-on-one-cpu-or-on-all-eight.md b/issues/kernel/a-log-write-to-the-t14s-stick-masks-interrupts-for-its-whole-usb-transfer-on-one-cpu-or-on-all-eight.md index 03685a593a5..95ff8562ecb 100644 --- a/issues/kernel/a-log-write-to-the-t14s-stick-masks-interrupts-for-its-whole-usb-transfer-on-one-cpu-or-on-all-eight.md +++ b/issues/kernel/a-log-write-to-the-t14s-stick-masks-interrupts-for-its-whole-usb-transfer-on-one-cpu-or-on-all-eight.md @@ -19,8 +19,8 @@ on it waits as long, masked. Read in one T14 boot of `main` at `c59e09ed6` with a throwaway instrument that records every window of 2 ms or more with the addresses that opened and closed it, its CPU's last events, and samples of that CPU every 2 ms; the boot ran -`test_rs_ring_park_herd` forty times. Its lines are quoted on the pull request -that landed this text. Pid 4 is that fsd. +`test_rs_ring_park_herd` forty times. Its lines are quoted on #681 (comments +5962618149, 5962618492 and 5962618868). Pid 4 is that fsd. - **Eleven writes of 7.8 ms or more in 37 s**, 2.0 to 4.6 s apart, each window opened at the syscall's entry and closed at its return. Nine are on one CPU diff --git a/issues/kernel/cpu0-holds-interrupts-and-preemption-off-for-6-5-ms-on-the-t14.md b/issues/kernel/cpu0-holds-interrupts-and-preemption-off-for-6-5-ms-on-the-t14.md index 2631deba979..a2912b31a8b 100644 --- a/issues/kernel/cpu0-holds-interrupts-and-preemption-off-for-6-5-ms-on-the-t14.md +++ b/issues/kernel/cpu0-holds-interrupts-and-preemption-off-for-6-5-ms-on-the-t14.md @@ -41,7 +41,7 @@ records. It is init in `SYS_DEVICE_CLAIM`. One boot of `main` at `c59e09ed6` with a throwaway instrument that names a window's opener and samples its CPU every -2 ms (its lines quoted on the pull request that landed this text) read cpu0's +2 ms (#681, comment 5962618149) read cpu0's line at 6623907 and 6623757 and named that window: pid 0, opened at the syscall's entry and closed at its return, from 1.179 s, both samples in `XhciController::wait_transfer` under `storage_read`. Two more of init's From 2529aba5511ff030e1b3d31349229240cb118aac Mon Sep 17 00:00:00 2001 From: japabu Date: Sat, 3 Oct 2026 01:33:48 +0200 Subject: [PATCH 03/11] issues: one record of the xHCI spin; the PCI claim and the firmware's interrupt keep their own, with owners and exits Review round 1 of #681 found the T14's log-write file a third record of the spin `issues/hardware/xhci-waits-are-spins.md` and `a-disk-operation-can-spin-past-the-tlb-ack-tripwire-before-its-break` already held, with the cpu0 file's partition claims a fourth. - xhci-waits-are-spins.md is the one record: the spin, a disk call's masked syscall, the tripwire arithmetic (folded from the deleted a-disk-operation file), the T14 readings (folded from the deleted log-write file), init's partition claims and #649's readings that are this by reading. Owner: the small-kernel track's step 10. Exit: the tree has no kernel/src/drivers/xhci. Old content dropped as no longer true of the tree: the hot-plug enumeration's ~14 ms (it is stepped now) and the "I/O thread or asynchronous block layer" choice (the track chose usbd). - The cpu0 file keeps only the 3.8 ms PCI claim and is renamed inits-claim-of-a-pci-function-the-t14-lacks-holds-interrupts-off-for-3-8-ms: its 6.5 ms is the spin's. Owner: the same track (stage 5's exit, step 10 unmasking cpu0's line). Exit: the mask_windows row's first report reads cpu0 under 3,817,265 ns after step 10. - The firmware file drops "and not under Linux" from its slug: Linux's 0 was read beside rtla timerlat --dma-latency 0 only. It states the Linux ACPI values as read (comment 5962768253), shows the stop by the two lock gaps instead of a late sample, names the T14 loop as owner of the row, and its exit reads the count from init's spawn to the stop's report, after any SMI_CMD write the bring-up makes. - Corrections: the writing CPU acknowledges 130 to 264 ns before each of the fourteen long shootdowns ends; the stop's report read two CPUs over 10 ms in 649-r5/1-head; the walk reads 1.03 to 1.98 ms without the log write and the firmware step. The instrument's control bullet is removed. - a-shutdown-on-a-held-usb-disk's citation of the deleted file follows it. Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_013UDZQ6fSKw14e4w2TKTRfm --- ...upts-every-cpu-every-2-2-s-under-toyos.md} | 44 +++--- issues/hardware/xhci-waits-are-spins.md | 130 ++++++++++++------ ...t-the-tlb-ack-tripwire-before-its-break.md | 26 ---- ...usb-transfer-on-one-cpu-or-on-all-eight.md | 75 ---------- ...alk-by-the-threads-it-parks-on-one-ring.md | 14 +- ...disk-left-a-cpu-deaf-to-a-tlb-shootdown.md | 4 +- ...nd-preemption-off-for-6-5-ms-on-the-t14.md | 66 --------- ...4-lacks-holds-interrupts-off-for-3-8-ms.md | 32 +++++ 8 files changed, 159 insertions(+), 232 deletions(-) rename issues/hardware/{the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos-and-not-under-linux.md => the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md} (53%) delete mode 100644 issues/kernel/a-disk-operation-can-spin-past-the-tlb-ack-tripwire-before-its-break.md delete mode 100644 issues/kernel/a-log-write-to-the-t14s-stick-masks-interrupts-for-its-whole-usb-transfer-on-one-cpu-or-on-all-eight.md delete mode 100644 issues/kernel/cpu0-holds-interrupts-and-preemption-off-for-6-5-ms-on-the-t14.md create mode 100644 issues/kernel/inits-claim-of-a-pci-function-the-t14-lacks-holds-interrupts-off-for-3-8-ms.md diff --git a/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos-and-not-under-linux.md b/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md similarity index 53% rename from issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos-and-not-under-linux.md rename to issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md index 277c3282783..00e84c64afa 100644 --- a/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos-and-not-under-linux.md +++ b/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md @@ -4,7 +4,7 @@ kind: defect opened: 2026-10-03 --- -# The T14's firmware interrupts every CPU every 2.2 s under ToyOS, and not under Linux +# The T14's firmware interrupts every CPU every 2.2 s under ToyOS On LENOVO 20W0003AMZ, BIOS N34ET71W (1.71), one boot of `main` at `c59e09ed6` with a throwaway instrument that reads `MSR_SMI_COUNT` (MSR 0x34) on each CPU @@ -21,14 +21,15 @@ lines are quoted on #681 (comment 5962619169; the boot itself in comment - **Each step stops every CPU for about 4.5 ms.** The 25 interrupts-off windows a step falls in read 4,529,514 to 4,764,935 ns: sixteen open in a job's syscall or interrupt, thirteen of them `SYS_SYSINFO`, and nine in a - pass leaving idle. None of those sections reads 2 ms where no step falls. - Each window has one sample of its CPU, 4.52 to 4.70 ms after it opened, - where a CPU the instrument holds masked on purpose is sampled every 2 ms. At - 9.925 s all eight CPUs carry one at once. Two CPUs waiting on a lock across a - step went 4,503,694 and 4,554,675 ns between two turns of their own spin. -- **Under Linux it does not move.** On the same machine under Ubuntu's + pass leaving idle. None of those sections reads 2 ms where no step falls. At + 9.925 s all eight CPUs carry one at once. That the CPU stops is shown by two + CPUs waiting on a lock across a step, which went 4,503,694 and 4,554,675 ns + between two turns of their own spin. +- **Linux, in one condition, read none.** On the same machine under Ubuntu's `6.8.0-142-generic`, `perf stat -a -A -e msr/smi/` read 0 on every CPU over - 120.378 s. + 120.378 s beside `rtla timerlat top -q -d 2m --dma-latency 0`, which holds + every CPU's C-states shallow and runs a 1 kHz timer on each. Linux idle has + not been read. What differs, as far as anything has read: @@ -38,16 +39,27 @@ What differs, as far as anything has read: (`kernel/src/drivers/xhci/legacy.rs`), and nothing reads `PM1a_CNT.SCI_EN` or the chipset's `SMI_EN`. Both controllers' `USBLEGCTLSTS` read `0xe0000000`, no enable set, before the handoff wrote it. -- Under that Linux the orchestrator reports the FADT's `SMI_CMD=0xb2` and - `ACPI_ENABLE=0xf0`, `PM1a_CNT.SCI_EN=1` and `SMI_EN=0x10002033`. The output - of those reads was not kept. +- Under that Linux, read as root from `/sys/firmware/acpi/tables/FACP` and + `/dev/port` with nothing written (comment 5962768253): the FADT's + `SMI_CMD=0xb2` and `ACPI_ENABLE=0xf0`; `PM1a_CNT` (port 0x1804) `0x0001`, + `SCI_EN` set; `SMI_EN` (port 0x1830) `0x10002033`, bits 0 (`GBL_SMI_EN`), 1 + (`EOS`), 4 (`SLP_SMI_EN`), 5 (`APMC_EN`), 13 (`TCO_EN`) and 28. - Under ToyOS neither `SCI_EN` nor `SMI_EN` has been read. The cause is not known. The `mask-windows` kernel prints such a window as its -CPU's own: the lines of 4,720,498 and 4,725,822 ns in #649's boots -(`issues/kernel/cpu0-holds-interrupts-and-preemption-off-for-6-5-ms-on-the-t14.md`, -`issues/kernel/a-process-lengthens-an-interrupts-off-walk-by-the-threads-it-parks-on-one-ring.md`) +CPU's own: cpu4's 4,720,498 ns in the sixth of #649's `mask_windows` boots at +`72f16e39a`, and cpu0's 4,725,822 in `649-r6/3-idle-halt-counted` +(`issues/kernel/a-process-lengthens-an-interrupts-off-walk-by-the-threads-it-parks-on-one-ring.md`), are this by reading, those kernels not reading the count. -**Exit**: `MSR_SMI_COUNT` does not move during a boot on the T14, read by a -row. +The ACPI enable is itself a write of `ACPI_ENABLE` to `SMI_CMD`, which raises +one firmware interrupt where `APMC_EN` is set, so a boot that tests it reads +the count over an interval after that write, never across it. + +**Owner**: the T14 loop +(`issues/hardware/the-t14-boots-toyos-unattended.md`), whose jobs are the +measurements owed on hardware: it builds the row. + +**Exit**: a T14 row reads `MSR_SMI_COUNT` on every CPU as init is spawned, +after every write the kernel's bring-up makes, and again at the stop's report, +and on every CPU the two agree. diff --git a/issues/hardware/xhci-waits-are-spins.md b/issues/hardware/xhci-waits-are-spins.md index 7688c20d68d..e675c295721 100644 --- a/issues/hardware/xhci-waits-are-spins.md +++ b/issues/hardware/xhci-waits-are-spins.md @@ -4,44 +4,92 @@ kind: defect opened: 2026-08-03 --- -# The xHCI driver's waits are spins with preemption disabled, wherever they run - -`bdf2596` moved the *boundary* — an input read no longer drives the driver — so -the only thread that runs enumeration and recovery now is the one inside -`drain_irqs`. That fixes who pays; it does not change what is paid. - -Every wait in this driver is a spin against a wall-clock deadline, taken while -holding `XHCI`, which is a ticket spinlock and therefore preemption off for its -whole life: - -- `settles()` — controller halt, HCRST, CNR, R/S, and the port reset. Bound - `USB_TIMEOUT_NS`, 2 s. -- `wait_command()` and `wait_transfer()` — every command and every transfer. - Same bound. - -**The port machine took the two that ran inside a scheduler pass out of that -list.** A teardown's Disable Slot and an endpoint recovery's three-in-a-row -(Reset or Stop Endpoint, Set TR Dequeue, CLEAR_FEATURE(HALT)) are -submit-and-return now, so the six seconds above are reachable only from the boot -path and from `storage_read`/`storage_write` — the first has no scheduler to -give a pass back to, and the second is the case named below that this conversion -does not fix. - -So a worst case is a CPU that does not reschedule for **six seconds**, and an -ordinary hot-plug enumeration on the T14 is ~14 ms of it (`hotplug-blocks-a-scheduler-pass`). -Nothing in the suite can measure the bad case: QEMU answers every one of these -in microseconds, which is why a driver built entirely out of them passed -everything here for a season. - -**The hot-plug half of that conversion has landed**: enumeration is -`device::begin`/`stepped`, submit-and-return, driven by the port machine — so -no runtime path blocks a scheduler pass on it any more. `restart_endpoint`'s -half is done the same way: the route is `toyos_xhci::recovery`'s, driven twice -— a blocking loop for a disk's bulk pair, which runs on the thread that -faulted, and a stepped one for HID. - -One case is *not* fixed by that and needs its own answer: `storage_read` and -`storage_write` are called by the page cache on a faulting thread, so a thread -touching a file on a USB disk drives a SCSI command under the same lock. The -input poll was gratuitous and could simply be deleted; this one is inherent, and -the choice is between an I/O thread and making the block layer asynchronous. +# The xHCI driver's waits are spins, and a USB disk call spins with interrupts masked + +Every wait in the kernel's xHCI driver spins against a wall-clock deadline +while holding `XHCI` (`kernel/src/drivers/xhci/mod.rs`), a ticket spinlock and +so preemption off for its whole life: `settles()` for the controller's halt, +reset and port reset, and `wait_command()` and `wait_transfer()` for every +command and transfer, each bounded by `USB_TIMEOUT_NS`, 2 s. The port +machine's enumeration and HID recovery submit and return; what still spins is +the boot path's bring-up, the stop, and a disk call. + +A call on a USB disk holds `XHCI` from its first command (`with_disk`, +`kernel/src/drivers/xhci/wait/msc.rs`) inside a syscall, which runs with +interrupts masked from entry to exit +(`issues/kernel/syscall-preemption-is-incidental.md`): a partition claim's +`SYS_PARTITION_READ` and `SYS_PARTITION_WRITE`, and the table +`SYS_DEVICE_CLAIM` reads for one (`gpt::claimable`, `kernel/src/gpt.rs`). So +its CPU holds interrupts and preemption off for as long as the device takes, +and a CPU whose TLB shootdown waits on that CPU's acknowledgement spins as +long, masked. + +**Its bound outruns the TLB-ack tripwire.** `time::DEAF_CPU` (5 s), past which +a CPU waiting on an acknowledgement panics, is held above `CALL_AFTER_BREAK` +(4.75 s), the longest a disk call spins once its transport has broken. But that +bound opens at the wait that broke, and `transfer_blocks` starts a batch while +the operation's 2 s `block::OPERATION` has any left: a batch that starts at +1.99 s and breaks runs its ladder to 6.74 s after the operation began, all of +it with `IF` clear. That is arithmetic on the declared constants; no boot has +been seen to do it. + +## On the T14 + +On LENOVO 20W0003AMZ, BIOS N34ET71W (1.71), `/log` is a FAT32 partition of the +USB stick the machine boots from, which `/system/bin/fsd` in the LOG role +writes with `SYS_PARTITION_WRITE`. One boot of `main` at `c59e09ed6` with a +throwaway instrument that records every window of 2 ms or more with the +addresses that opened and closed it, its CPU's last events, and samples of +that CPU every 2 ms ran `test_rs_ring_park_herd` forty times. Its lines are +quoted on #681 (comments 5962618149, 5962618492 and 5962618868). Pid 4 is that +fsd. + +- **Eleven writes of 7.8 ms or more in 37 s**, 2.0 to 4.6 s apart, each window + opened at the syscall's entry and closed at its return. Nine are on one CPU + alone: 8,289,211 to 10,669,042 ns. 36 of their 37 samples are in + `wait_transfer < bulk < bot < scsi < transfer_blocks` under `storage_write`; + the 37th is the same syscall waiting for the process table's lock. +- **All eight CPUs at once, twice**, at 17.416 s and 21.116 s: the write on one + CPU (7,848,573 and 7,927,725 ns) while a herd thread on each of the other + seven is in `SYS_THREAD_EXIT`, whose unmap shoots down every CPU's TLB. The + fourteen shootdowns span 7,703,612 to 7,852,515 ns, and their initiators + spin: none goes more than 10,819 ns between two turns of its wait. The other + targets acknowledge within 24 µs; the writing CPU acknowledges by interrupt + once its syscall has returned, 130 to 264 ns before each shootdown ends. Each + event is followed at once by a shorter one of the same shape: the next + write, 2,824,878 and 2,846,782 ns, and fourteen more shootdowns. The + report's `tlb:` line reads `max=7846us` after the first, where it read + `max=1146us` before it. +- **Shorter**: sixteen of the same server's writes read 2,368,371 to + 2,905,716 ns, those two among them, and two of its `SYS_PARTITION_READ` + 2,596,003 and 2,954,780. At the stop, the black box keeps a write opened at + 38.795 s whose CPU's next event comes 7,953,409 ns later. +- **init's partition claims**: on cpu0, 6,002,063 ns at 1.171 s and + 6,623,907 ns at 1.179 s, each `SYS_DEVICE_CLAIM` from entry to return, all + four samples in `wait_transfer` under `storage_read`. +- **Not the firmware**: `MSR_SMI_COUNT` does not move across any of them. The + windows it does move across are + `issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md`'s. + +The `mask-windows` kernel (`kernel/src/windows.rs`) prints a span and no +opener, and #649's T14 boots printed these by reading: + +- cpu0's line before the first job's exit, init's partition claims: + 6,540,326 to 6,590,095 ns in seven of the eight `mask_windows` boots at + `72f16e39a`, and 6,533,222, 2 × 3,273,547 and 6,508,165 in the first report + of the three at `8b73eba69` (comment 5959415453). +- Every CPU at once: 9,603,617 to 9,651,846 ns beside `tlb: … max=9575us`, the + fourth boot at `72f16e39a`; 2 × 5,014,552 to 2 × 5,075,290 beside + `max=10038us`, `649-r6/2-report-halved` (comment 5960575031). +- One CPU alone: 9,260,193, the seventh boot at `72f16e39a`; cpu7, where pid 4 + started, at 11,492,028 and 8,456,658 before the first job's exit + (`649-r6/1-head`, `649-r6/3-idle-halt-counted`). +- The stop's report: one CPU at 10,214,820 to 11,267,384 in four boots at + `72f16e39a`, and two in `649-r5/1-head`, cpu7 at 11,522,834 and cpu4 at + 11,645,411 (`loader.log:57`, `:63`). + +**Owner**: `issues/kernel/the-kernel-is-small-interrupts-post-and-threads-wait.md`, +whose step 10 moves the whole xHCI to usbd and deletes the kernel's driver. + +**Exit**: the tree has no `kernel/src/drivers/xhci`, so no kernel wait is a USB +device's. diff --git a/issues/kernel/a-disk-operation-can-spin-past-the-tlb-ack-tripwire-before-its-break.md b/issues/kernel/a-disk-operation-can-spin-past-the-tlb-ack-tripwire-before-its-break.md deleted file mode 100644 index ee0f09fa33f..00000000000 --- a/issues/kernel/a-disk-operation-can-spin-past-the-tlb-ack-tripwire-before-its-break.md +++ /dev/null @@ -1,26 +0,0 @@ ---- -status: open -kind: defect -opened: 2026-09-22 ---- - -# A disk operation can spin past the TLB-ack tripwire before its break - -`time::DEAF_CPU` (5 s), the TLB-ack tripwire, is held above xHCI's `CALL_AFTER_BREAK` -(4.75 s), "the longest a disk call spins with `IF` clear once its transport has -broken". But the call's bound is measured from the wait that broke, and a USB -disk operation holds the controller lock — `IF` clear — from its first command: -`transfer_blocks` sends one command per `MSC_MAX_BLOCKS` batch, and starts a -batch while the operation's 2 s `block::OPERATION` budget has any left. A batch -that starts at 1.99 s and breaks runs its ladder to 1.99 + 4.75 = 6.74 s after -the operation began, all of it with `IF` clear: past the tripwire on any CPU -waiting for this one's TLB acknowledgement. That is arithmetic on the declared -constants; no boot has been seen to do it. - -## Exit condition - -The whole of one operation's `IF`-clear spin is under `DEAF_CPU` by -construction — the call bound opens where the operation does, or a later batch -starts only with a whole call's bound still inside it — and a staged boot in -which the first batch spends most of the budget and the next one breaks shows -the operation ending inside it. diff --git a/issues/kernel/a-log-write-to-the-t14s-stick-masks-interrupts-for-its-whole-usb-transfer-on-one-cpu-or-on-all-eight.md b/issues/kernel/a-log-write-to-the-t14s-stick-masks-interrupts-for-its-whole-usb-transfer-on-one-cpu-or-on-all-eight.md deleted file mode 100644 index 95ff8562ecb..00000000000 --- a/issues/kernel/a-log-write-to-the-t14s-stick-masks-interrupts-for-its-whole-usb-transfer-on-one-cpu-or-on-all-eight.md +++ /dev/null @@ -1,75 +0,0 @@ ---- -status: open -kind: defect -opened: 2026-10-02 ---- - -# A log write to the T14's stick masks interrupts for its whole USB transfer, on one CPU or on all eight - -On LENOVO 20W0003AMZ, BIOS N34ET71W (1.71), `/log` is a FAT32 partition of the -USB stick the machine boots from, and `/system/bin/fsd` in the LOG role writes -it with `SYS_PARTITION_WRITE`, which the kernel's USB mass storage serves. The -kernel waits for the transfer by spinning on the event ring under the -controller's lock (`XhciController::wait_transfer`, -`kernel/src/drivers/xhci/wait/mod.rs`), inside a syscall, which runs with -interrupts masked from entry to exit. So the writing CPU holds interrupts and -preemption off for as long as the stick takes, and a CPU whose shootdown waits -on it waits as long, masked. - -Read in one T14 boot of `main` at `c59e09ed6` with a throwaway instrument that -records every window of 2 ms or more with the addresses that opened and closed -it, its CPU's last events, and samples of that CPU every 2 ms; the boot ran -`test_rs_ring_park_herd` forty times. Its lines are quoted on #681 (comments -5962618149, 5962618492 and 5962618868). Pid 4 is that fsd. - -- **Eleven writes of 7.8 ms or more in 37 s**, 2.0 to 4.6 s apart, each window - opened at the syscall's entry and closed at its return. Nine are on one CPU - alone: 8,289,211 to 10,669,042 ns. 36 of their 37 samples are in - `wait_transfer < bulk < bot < scsi < transfer_blocks` under `storage_write`; - the 37th is the same syscall waiting for the process table's lock. -- **All eight CPUs at once, twice**, at 17.416 s and 21.116 s: the write on one - CPU (7,848,573 and 7,927,725 ns) while a herd thread on each of the other - seven is in `SYS_THREAD_EXIT`, whose unmap shoots down every CPU's TLB. The - fourteen shootdowns span 7,703,612 to 7,852,515 ns, and their initiators - spin: none goes more than 10,819 ns between two turns of its wait. The other - targets acknowledge within 24 µs; the writing CPU acknowledges by interrupt - once its syscall has returned, 74 to 299 ns before each shootdown ends. Each - event is followed at once by a shorter one of the same shape: the next - write, 2,824,878 and 2,846,782 ns, and fourteen more shootdowns. The - report's `tlb:` line reads `max=7846us` after the first, where it read - `max=1146us` before it. -- **Shorter**: sixteen of the same server's writes read 2,368,371 to - 2,905,716 ns, those two among them, and two of its - `SYS_PARTITION_READ` 2,596,003 and 2,954,780. At the stop, the black box - keeps a write opened at 38.795 s whose CPU's next event comes - 7,953,409 ns later. -- **Not the firmware**: `MSR_SMI_COUNT` does not move across any of them. The - windows it does move across are - `issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos-and-not-under-linux.md`'s. -- **The instrument's control**: a 50,000,024 ns hold reads back as a - 56,000,902 ns window on its CPU, sampled in `kernel::windows::hold_once` - every 2 ms. The excess is the instrument's own report, which that same - `SYS_EXIT` prints (5,918,088 ns): a window on a CPU printing a report - includes the report. - -The `mask-windows` kernel (`kernel/src/windows.rs`) prints a span and no -opener. #649's fourteen T14 boots printed spans that are these writes by -reading, no opener having been recorded: every CPU at once at 9,603,617 to -9,651,846 ns beside `tlb: … max=9575us` (the fourth `mask_windows` boot at -`72f16e39a`) and at 2 × 5,014,552 to 2 × 5,075,290 beside `max=10038us` -(`649-r6/2-report-halved`, comment 5960575031); one CPU alone at 9,260,193 -(the seventh at `72f16e39a`); cpu7, where pid 4 started in both boots, at -11,492,028 and 8,456,658 before the first job's exit (`649-r6/1-head`, -`649-r6/3-idle-halt-counted`); and one CPU at 10,214,820 to 11,645,411 in the -stop's report of five boots. - -The window goes when the kernel stops serving the stick: -`issues/kernel/the-kernel-is-small-interrupts-post-and-threads-wait.md`'s -step 10 moves the xHCI to usbd, and its stage 5 exits on no interrupts-off -window longer than a register access. The waiters are masked because a -syscall is (`issues/kernel/syscall-preemption-is-incidental.md`). - -**Exit**: a T14 boot that writes the log as this one did prints no -interrupts-off window that a USB transfer opens, read by an instrument that -names a window's opener; or this file is replaced by the bound the write is -held to and the derivation of it. diff --git a/issues/kernel/a-process-lengthens-an-interrupts-off-walk-by-the-threads-it-parks-on-one-ring.md b/issues/kernel/a-process-lengthens-an-interrupts-off-walk-by-the-threads-it-parks-on-one-ring.md index 31f5404bfbf..d0dc5d77598 100644 --- a/issues/kernel/a-process-lengthens-an-interrupts-off-walk-by-the-threads-it-parks-on-one-ring.md +++ b/issues/kernel/a-process-lengthens-an-interrupts-off-walk-by-the-threads-it-parks-on-one-ring.md @@ -57,13 +57,15 @@ mutated kernels) read the same report of the same load at 1980239 969922 to 1044783. - 2 × 5075290 is one of eight: every CPU reads 2 × 5014552 to 2 × 5075290 (`:416` to `:430`), beside `tlb: shootdowns=282 wait=131633us max=10038us` - (`:431`). It is the all-CPU shape of - `issues/kernel/a-log-write-to-the-t14s-stick-masks-interrupts-for-its-whole-usb-transfer-on-one-cpu-or-on-all-eight.md`. -- 4725822 is cpu0's. The other seven read 544283 to 1018355. + (`:431`). It is a log write's all-CPU shape + (`issues/hardware/xhci-waits-are-spins.md`) by reading. +- 4725822 is cpu0's, a firmware step's length by reading + (`issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md`). + The other seven read 544283 to 1018355. -So one size reads 1.03 to 10.15 ms over six boots, and which boot carried -one of the machine's own events decides a single reading. None of the six -took an interrupt a handler #634 changed serves +So one size reads 1.03 to 1.98 ms in the four of those reports none of the +machine's own events reached, and which boot carried one decides a single +reading. None of the six took an interrupt a handler #634 changed serves (`userdev=0 sound=0 dmafault=0 hda=0` on every CPU). **Exit**: the interrupts-off window step 2's instrument reads on the T14 diff --git a/issues/kernel/a-shutdown-on-a-held-usb-disk-left-a-cpu-deaf-to-a-tlb-shootdown.md b/issues/kernel/a-shutdown-on-a-held-usb-disk-left-a-cpu-deaf-to-a-tlb-shootdown.md index 1baf4cb4031..79cca8589e3 100644 --- a/issues/kernel/a-shutdown-on-a-held-usb-disk-left-a-cpu-deaf-to-a-tlb-shootdown.md +++ b/issues/kernel/a-shutdown-on-a-held-usb-disk-left-a-cpu-deaf-to-a-tlb-shootdown.md @@ -29,8 +29,8 @@ accord is logd's network thread, on a boot that gives logd no netd; the logd branch no longer starts that thread there, which would remove this boot's trigger and not the deaf CPU. -`a-disk-operation-can-spin-past-the-tlb-ack-tripwire-before-its-break.md` is -the arithmetic for one disk operation outrunning `time::DEAF_CPU`; this is a boot +`issues/hardware/xhci-waits-are-spins.md` carries the arithmetic for one disk +operation outrunning `time::DEAF_CPU`; this is a boot that did outrun it, in `quiesce`, across several operations each inside its own budget. Whether `quiesce` holds `IF` clear between them is not measured. diff --git a/issues/kernel/cpu0-holds-interrupts-and-preemption-off-for-6-5-ms-on-the-t14.md b/issues/kernel/cpu0-holds-interrupts-and-preemption-off-for-6-5-ms-on-the-t14.md deleted file mode 100644 index a2912b31a8b..00000000000 --- a/issues/kernel/cpu0-holds-interrupts-and-preemption-off-for-6-5-ms-on-the-t14.md +++ /dev/null @@ -1,66 +0,0 @@ ---- -status: open -kind: defect -opened: 2026-10-02 ---- - -# cpu0 holds interrupts and preemption off for 6.5 ms on the T14 - -Read by the `mask-windows` kernel (`kernel/src/windows.rs`) on LENOVO -20W0003AMZ, BIOS N34ET71W (1.71), in the eight `mask_windows` boots of #649 -at `72f16e39a`: four as that head stands and four with stage 6 step 1 (#634) -reverted on it. Each boot printed one report, at `test_rs_ring_park_herd`'s -exit, so a line is its CPU's longest window from the moment it joined the -scheduler to that exit. - -cpu0's line, in the seven boots where no longer window covers it: - -| boot | `irqs_off_ns` | `preempt_off_ns` | -|---|---|---| -| 1, reverted | 6551791 | 6551707 | -| 2 | 6540754 | 6540671 | -| 3, reverted | 6549549 | 6549484 | -| 5, reverted | 6540326 | 6540262 | -| 6 | 6589053 | 6588992 | -| 7, reverted | 6590095 | 6590031 | -| 8 | 6587342 | 6587281 | - -- The two kinds differ by 61 to 84 ns in every row, so one section holds - both. -- It is cpu0's alone. In the six of those boots where no CPU carries a - longer one, the other seven CPUs' interrupts-off lines read 251,452 to - 4,720,498 ns. -- It is there with step 1 and without it. -- In all eight logs cpu0 says `sched: cpu=0 ready=0 … current=None trips=1` - at 1.155 or 1.156 s, as the CPUs join the scheduler, and nothing more - before init's first line at 1.161 or 1.162 s. - -The fourth boot's cpu0 reads 9644415 and 9643939, the event -`issues/kernel/a-log-write-to-the-t14s-stick-masks-interrupts-for-its-whole-usb-transfer-on-one-cpu-or-on-all-eight.md` -records. - -It is init in `SYS_DEVICE_CLAIM`. One boot of `main` at `c59e09ed6` with a -throwaway instrument that names a window's opener and samples its CPU every -2 ms (#681, comment 5962618149) read cpu0's -line at 6623907 and 6623757 and named that window: pid 0, opened at the -syscall's entry and closed at its return, from 1.179 s, both samples in -`XhciController::wait_transfer` under `storage_read`. Two more of init's -claims precede it on cpu0: one at 1.171 s of 6,002,063 ns, both samples in -`wait_transfer` under `storage_read`, and one at 1.162 s of 3,817,265 ns, -whose one sample is in `PciDevice::is_id` under `pcidev::claim`. By reading, a -partition claim reads its disk's table when asked (`gpt::claimable`, -`kernel/src/gpt.rs`) through the same masked USB wait as that event's. Nothing -has said what the PCI claim spends 3.8 ms on. - -It opens before the boot's first job ends. The three boots of #649 at -`8b73eba69` (comment 5959415453, readbacks `649-r5/1-head`, -`649-r5/2-report-halved`, whose kernel prints half of every span, and -`649-r5/3-idle-halt-counted`) print a report at each of four exits. cpu0's -`irqs_off_ns` in the first, at `test_rs_idle_span`'s exit 1.746 s into the -boot (`windowscase/kernel.log:348` in each), reads 6533222, 2 × 3273547 and -6508165. In the three reports after it cpu0 reads at most 943904, 2 × 472938 -and 345229. - -**Exit**: on the T14, cpu0's longest window before the first job's exit no -longer includes init's claims, or this file is replaced by the bound they are -held to and the derivation of it. diff --git a/issues/kernel/inits-claim-of-a-pci-function-the-t14-lacks-holds-interrupts-off-for-3-8-ms.md b/issues/kernel/inits-claim-of-a-pci-function-the-t14-lacks-holds-interrupts-off-for-3-8-ms.md new file mode 100644 index 00000000000..792f559059b --- /dev/null +++ b/issues/kernel/inits-claim-of-a-pci-function-the-t14-lacks-holds-interrupts-off-for-3-8-ms.md @@ -0,0 +1,32 @@ +--- +status: open +kind: defect +opened: 2026-10-02 +--- + +# init's claim of a PCI function the T14 lacks holds interrupts off for 3.8 ms + +On LENOVO 20W0003AMZ, BIOS N34ET71W (1.71), one boot of `main` at `c59e09ed6` +with a throwaway instrument that names a window's opener and samples its CPU +every 2 ms (#681, comment 5962618149) read init's `SYS_DEVICE_CLAIM` for +blockd's `pci:1b36:0010`, which this machine does not have, holding cpu0's +interrupts off for 3,817,265 ns at 1.162 s, from the syscall's entry to its +return, with `MSR_SMI_COUNT` unmoved. Its one sample, 1.7 µs before it closed, +is in `PciDevice::is_id` under `pcidev::claim`. By reading, the claim reads the +vendor ID of each of the 24 functions the kernel enumerated +(`kernel/src/pcidev/mod.rs`); nothing has said what it spends 3.8 ms on. + +Before the first job's exit cpu0 also carries init's partition claims, 6.0 +and 6.6 ms in that boot (`issues/hardware/xhci-waits-are-spins.md`), and the +`mask-windows` kernel (`kernel/src/windows.rs`) prints each CPU's longest +window and no opener, so its cpu0 line there reads this claim only once those +have left the kernel. + +**Owner**: `issues/kernel/the-kernel-is-small-interrupts-post-and-threads-wait.md`, +whose stage 5 exits on no interrupts-off window longer than a register access, +and whose step 10 takes the partition claims off cpu0. + +**Exit**: after step 10, the T14's `mask_windows` row reads cpu0's +`irqs_off_ns` in its first report, at `test_rs_idle_span`'s exit, under +3,817,265 ns; or this file is replaced by the bound the claim is held to and +the derivation of it. From e25db7959500eb40802f2525dfc4be6d13a9fed1 Mon Sep 17 00:00:00 2001 From: japabu Date: Sat, 3 Oct 2026 08:49:09 +0200 Subject: [PATCH 04/11] issues: logd's fsync joins the xHCI spin's one record, which owes the tripwire's fix before step 10; the PCI and firmware exits are bounds a fix must clear Round 3 of #681's review (comment 5963284260). - issues/audio/disk-wait-pins-a-cpu.md was a second open record of the xHCI spin. Its one live claim is folded into issues/hardware/xhci-waits-are-spins.md: SYS_FSYNC on a partition claim (partition_fsync, kernel/src/object/ops.rs) is a cache flush through xhci::storage_flush under XHCI, inside a masked syscall, and logd's fsync is one, made by the LOG fsd on its claim (traced logd store.rs sync_all -> std fs toyos.rs Served fsync -> fsd FSYNC -> disk.rs PartitionDev::sync -> SYS_FSYNC). The rest of it is gone from the tree: log_file::SINK and fat32_adapter::VOLUMES no longer exist, the partition fsync takes no VFS, and io-depth-probe is no kernel feature. Its two citations: scheduler-pass-blocks-in-xhci.md now points at the surviving record; the-global-pipe-lock-spans-a-user-copy.md's clause naming it and io-depth-probe is deleted. In the scout boot no SYS_FSYNC window reached 2 ms (none of the 101 opened at sys(15)). - The spin's list of what still spins names a disk's bind after boot, which still blocks in a scheduler pass (msc::bind's doc, poll_if_pending's doc). - The fold's lost exit is restored beside step 10's, under the same owner: one operation's IF-clear spin under DEAF_CPU by construction, shown by a staged boot. The orchestrator ruled the cheaper fix stays owed. - The PCI claim's exit is a bound a fix must clear, 223 us, derived from 24 vendor-ID reads at the enumeration's bulk rate (7,871 absent reads in at most 73 ms), with MSR_SMI_COUNT unmoved so a firmware step cannot fail a fixed claim. The same enumeration read the 31 to 38 absent functions behind 00:1c.4 at about 80 to 160 us a read, the order of the claim's 159 us; the file says so. Lines quoted on #681, comment 5966492598. - The firmware issue's interval opens after the boot's last SMI_CMD write, whoever makes it, and its owner line says the T14 loop owns only the reading and the fix has none in the tree yet: the owner approved a scout of the switch to ACPI mode, and the fix's ownership is put to him with its result. - issues/kernel/the-scheduler-and-the-clocks-never-talk.md cited an "ACPI/power track (task #136)" that has no file; the citation goes and the AML interpreter idle-cpus-enter-the-c-states-cst-names.md points at stays. Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_013UDZQ6fSKw14e4w2TKTRfm --- issues/audio/disk-wait-pins-a-cpu.md | 29 ----------------- ...rupts-every-cpu-every-2-2-s-under-toyos.md | 20 ++++++------ issues/hardware/xhci-waits-are-spins.md | 32 +++++++++++++------ ...4-lacks-holds-interrupts-off-for-3-8-ms.md | 15 ++++++--- .../kernel/scheduler-pass-blocks-in-xhci.md | 2 +- .../the-global-pipe-lock-spans-a-user-copy.md | 2 +- ...the-scheduler-and-the-clocks-never-talk.md | 5 ++- 7 files changed, 48 insertions(+), 57 deletions(-) delete mode 100644 issues/audio/disk-wait-pins-a-cpu.md diff --git a/issues/audio/disk-wait-pins-a-cpu.md b/issues/audio/disk-wait-pins-a-cpu.md deleted file mode 100644 index a02bb9b617f..00000000000 --- a/issues/audio/disk-wait-pins-a-cpu.md +++ /dev/null @@ -1,29 +0,0 @@ ---- -status: open -kind: defect -opened: 2026-08-08 ---- - -# The audio pops are four spinlocks, not one spinning driver - -Measured 2026-08-08 on `wt/toyos-asyncusb` at `87835d1`: at the moment a disk -transfer is waited for, an ordinary guest is **four ticket spinlocks deep** — -`log_file::SINK`, `vfs::VFS`, `fat32_adapter::VOLUMES` and `xhci::XHCI` — and -every one of them disables preemption for its whole life. `io-depth-probe` -(kernel feature) reports the depth with the backtrace that got there: 4 from the -idle loop, 5 from a syscall. So **making `xhci::wait_transfer` park cannot work -and would not help**: `prepare_wait` asserts the depth equals the context's -baseline, so a park there is a named panic on the first flush — and the three -locks above `XHCI` would still hold the CPU if it were not. -`object/ops.rs:619` (`fsync`, formerly `fd.rs:644` before the handle-table -rewrite) puts every userland file write-back at the same depth, so this is not a property of -the log sink; it is that this kernel cannot touch a disk without pinning a CPU -for the whole device round trip. The log sink is only the writer that runs -continuously, which is why it is the one gate A sees. - -The log-flush deferral fix — whose affordability heuristic left the kernel with -the log architecture, so no CPU takes a flush now — and -[`stop-the-device-voice-keep-the-wake.md`](stop-the-device-voice-keep-the-wake.md) -are the fixes that came before. Each was right about its own defect; both chose -which CPU absorbs a stall whose duration neither touched. The pinning disk wait -is logd's `fsync` through the three spinlocks above. diff --git a/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md b/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md index 00e84c64afa..e6144114283 100644 --- a/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md +++ b/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md @@ -52,14 +52,14 @@ CPU's own: cpu4's 4,720,498 ns in the sixth of #649's `mask_windows` boots at (`issues/kernel/a-process-lengthens-an-interrupts-off-walk-by-the-threads-it-parks-on-one-ring.md`), are this by reading, those kernels not reading the count. -The ACPI enable is itself a write of `ACPI_ENABLE` to `SMI_CMD`, which raises -one firmware interrupt where `APMC_EN` is set, so a boot that tests it reads -the count over an interval after that write, never across it. +**Owner**: the T14 loop (`issues/hardware/the-t14-boots-toyos-unattended.md`) +owns only the reading: its jobs are the measurements owed on hardware, and it +builds the row. The fix has no owner in the tree yet: the owner has approved a +scout of the switch to ACPI mode, and who owns a fix is put to him with the +scout's result. -**Owner**: the T14 loop -(`issues/hardware/the-t14-boots-toyos-unattended.md`), whose jobs are the -measurements owed on hardware: it builds the row. - -**Exit**: a T14 row reads `MSR_SMI_COUNT` on every CPU as init is spawned, -after every write the kernel's bring-up makes, and again at the stop's report, -and on every CPU the two agree. +**Exit**: a T14 row reads `MSR_SMI_COUNT` on every CPU after init is spawned +and after the boot's last write to `SMI_CMD`, whoever makes it, and again at +the stop's report, and on every CPU the two agree. The interval opens after +that write because the ACPI enable is one, a write of `ACPI_ENABLE` to +`SMI_CMD`, and raises one firmware interrupt where `APMC_EN` is set. diff --git a/issues/hardware/xhci-waits-are-spins.md b/issues/hardware/xhci-waits-are-spins.md index e675c295721..f7291b4d0fe 100644 --- a/issues/hardware/xhci-waits-are-spins.md +++ b/issues/hardware/xhci-waits-are-spins.md @@ -12,17 +12,22 @@ so preemption off for its whole life: `settles()` for the controller's halt, reset and port reset, and `wait_command()` and `wait_transfer()` for every command and transfer, each bounded by `USB_TIMEOUT_NS`, 2 s. The port machine's enumeration and HID recovery submit and return; what still spins is -the boot path's bring-up, the stop, and a disk call. +the boot path's bring-up, the stop, a disk's bind after boot, inside a +scheduler pass +(`issues/hardware/a-disk-plugged-in-after-boot-is-bound-inside-a-scheduling-pass.md`), +and a disk call. A call on a USB disk holds `XHCI` from its first command (`with_disk`, `kernel/src/drivers/xhci/wait/msc.rs`) inside a syscall, which runs with interrupts masked from entry to exit (`issues/kernel/syscall-preemption-is-incidental.md`): a partition claim's -`SYS_PARTITION_READ` and `SYS_PARTITION_WRITE`, and the table -`SYS_DEVICE_CLAIM` reads for one (`gpt::claimable`, `kernel/src/gpt.rs`). So -its CPU holds interrupts and preemption off for as long as the device takes, -and a CPU whose TLB shootdown waits on that CPU's acknowledgement spins as -long, masked. +`SYS_PARTITION_READ`, `SYS_PARTITION_WRITE` and `SYS_FSYNC`, the last a cache +flush through `xhci::storage_flush` (`partition_fsync`, +`kernel/src/object/ops.rs`), and the table `SYS_DEVICE_CLAIM` reads for one +(`gpt::claimable`, `kernel/src/gpt.rs`). logd's `fsync` is one of these: the +LOG fsd answers each with `SYS_FSYNC` on its claim. So its CPU holds +interrupts and preemption off for as long as the device takes, and a CPU whose +TLB shootdown waits on that CPU's acknowledgement spins as long, masked. **Its bound outruns the TLB-ack tripwire.** `time::DEAF_CPU` (5 s), past which a CPU waiting on an acknowledgement panics, is held above `CALL_AFTER_BREAK` @@ -67,6 +72,7 @@ fsd. - **init's partition claims**: on cpu0, 6,002,063 ns at 1.171 s and 6,623,907 ns at 1.179 s, each `SYS_DEVICE_CLAIM` from entry to return, all four samples in `wait_transfer` under `storage_read`. +- **No `SYS_FSYNC`** of that fsd's held interrupts off for 2 ms. - **Not the firmware**: `MSR_SMI_COUNT` does not move across any of them. The windows it does move across are `issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md`'s. @@ -89,7 +95,15 @@ opener, and #649's T14 boots printed these by reading: 11,645,411 (`loader.log:57`, `:63`). **Owner**: `issues/kernel/the-kernel-is-small-interrupts-post-and-threads-wait.md`, -whose step 10 moves the whole xHCI to usbd and deletes the kernel's driver. +whose step 10 moves the whole xHCI to usbd and deletes the kernel's driver. It +owes both exits. -**Exit**: the tree has no `kernel/src/drivers/xhci`, so no kernel wait is a USB -device's. +**Exit**, two: +- **The tripwire's, short of step 10**: the whole of one operation's `IF`-clear + spin is under `DEAF_CPU` by construction, because the call's bound opens + where the operation opens, or a later batch starts only while a whole call's + bound is still inside it; and a staged boot whose first batch spends most of + the budget and whose next batch breaks shows the operation ending inside + `DEAF_CPU`. +- **The spin's**: the tree has no `kernel/src/drivers/xhci`, so no kernel wait + is a USB device's. Step 10 meets both. diff --git a/issues/kernel/inits-claim-of-a-pci-function-the-t14-lacks-holds-interrupts-off-for-3-8-ms.md b/issues/kernel/inits-claim-of-a-pci-function-the-t14-lacks-holds-interrupts-off-for-3-8-ms.md index 792f559059b..6d892e51287 100644 --- a/issues/kernel/inits-claim-of-a-pci-function-the-t14-lacks-holds-interrupts-off-for-3-8-ms.md +++ b/issues/kernel/inits-claim-of-a-pci-function-the-t14-lacks-holds-interrupts-off-for-3-8-ms.md @@ -26,7 +26,14 @@ have left the kernel. whose stage 5 exits on no interrupts-off window longer than a register access, and whose step 10 takes the partition claims off cpu0. -**Exit**: after step 10, the T14's `mask_windows` row reads cpu0's -`irqs_off_ns` in its first report, at `test_rs_idle_span`'s exit, under -3,817,265 ns; or this file is replaced by the bound the claim is held to and -the derivation of it. +**Exit**: a T14 boot reads that claim's window, from the syscall's entry to +its return, under 223 µs, with `MSR_SMI_COUNT` unmoved across it. The bound +is an estimate: the claim's 24 vendor-ID reads at 9.3 µs each, the most a +read averaged over the last 7,871 or more of the same boot's enumeration, all +of absent functions, between `PCI 0a:00.0` at 0.072 s and `Enumeration +complete` at 0.144 s: at most 73 ms on stamps of whole milliseconds (#681, +comment 5966492598). Not every read was that fast: the 31 to 38 absent functions +behind `00:1c.4`, between `PCI 09:00.0` at 0.068 s and `PCI 0a:00.0`, took 3 +to 5 ms, about 80 to 160 µs a read, and 3,817,265 ns is 159 µs for each of +the claim's 24. A claim whose reads cost that clears this bound only by making +fewer. diff --git a/issues/kernel/scheduler-pass-blocks-in-xhci.md b/issues/kernel/scheduler-pass-blocks-in-xhci.md index 8fc7d5c0f3b..ac3cd70c74e 100644 --- a/issues/kernel/scheduler-pass-blocks-in-xhci.md +++ b/issues/kernel/scheduler-pass-blocks-in-xhci.md @@ -36,7 +36,7 @@ handing it on, gated by simulator invariant I14. This half is not. The second instance of the same shape used to be the idle loop's log flush; the idle loop touches no filesystem now — the log is logd's file — and the disk wait that survives, logd's `fsync` pinning a CPU for the device round -trip, is `issues/audio/disk-wait-pins-a-cpu.md`'s subject. +trip, is `issues/hardware/xhci-waits-are-spins.md`'s subject. Closing this means making xHCI enumeration and endpoint recovery asynchronous, so that `drain_irqs` only ever does work it can finish: drain the event ring, diff --git a/issues/kernel/the-global-pipe-lock-spans-a-user-copy.md b/issues/kernel/the-global-pipe-lock-spans-a-user-copy.md index a4ab14f071b..ae961f8815f 100644 --- a/issues/kernel/the-global-pipe-lock-spans-a-user-copy.md +++ b/issues/kernel/the-global-pipe-lock-spans-a-user-copy.md @@ -28,7 +28,7 @@ Everything pipe-shaped in the kernel goes through the same static: `create` (`pi This is **not** the device-I/O class. The copy is memory-speed and takes no device round trip, so it does not approach `sync::Lock`'s 500,000,000-spin `DEADLOCK` panic (`sync.rs:72-75`) the way a `block::Handle`'s device lock and `vfs::VFS` do — that class is tracked in `issues/kernel/every-wait-in-this-kernel-is-a-spin.md` and is not what this file is about. -What it is: a global lock held with preemption disabled for a stretch that scales with a userland-chosen length up to 2 MiB, on the path that carries every IPC message in the system. The scheduler's own bar for an uninterruptible stretch is `MAX_PASS_NS = 200_000` ns (`toyos-sched/src/cpu.rs:1235`); a 2 MiB copy plus, on first write, a 2 MiB zeroing and a bitmap scan is on the wrong side of that at any plausible memory bandwidth. **The hold time is not measured and that is the first thing owed** — `io-depth-probe` and the `audio_tone` worst-wake instrument are the tools that would price it, the same pair `issues/audio/disk-wait-pins-a-cpu.md` used for the device path. +What it is: a global lock held with preemption disabled for a stretch that scales with a userland-chosen length up to 2 MiB, on the path that carries every IPC message in the system. The scheduler's own bar for an uninterruptible stretch is `MAX_PASS_NS = 200_000` ns (`toyos-sched/src/cpu.rs:1235`); a 2 MiB copy plus, on first write, a 2 MiB zeroing and a bitmap scan is on the wrong side of that at any plausible memory bandwidth. **The hold time is not measured and that is the first thing owed.** Two things make it worth closing rather than noting. The convoy is machine-wide, not per-pipe: one process reading 2 MiB out of a full pipe stalls an unrelated process's `SYS_CONNECT` and an unrelated inbox's readiness poll. And it is directly userland-driven — the length is the caller's, so a program that wants the stall only has to ask for it. diff --git a/issues/kernel/the-scheduler-and-the-clocks-never-talk.md b/issues/kernel/the-scheduler-and-the-clocks-never-talk.md index 3e3e4cd0d92..7c3b9ac3917 100644 --- a/issues/kernel/the-scheduler-and-the-clocks-never-talk.md +++ b/issues/kernel/the-scheduler-and-the-clocks-never-talk.md @@ -19,8 +19,7 @@ Two couplings every production scheduler has and ours lacks: wake. A latency-sensitive wake should prefer a shallow-idle core; a throughput task can pay to wake a deep one. -Both wait for the ACPI/power track (task #136 — own AML interpreter, battery -first) because today the kernel neither reads nor sets P-states or C-states on -metal. Filed so the placement track (see +Both wait for an AML interpreter, because today the kernel neither reads nor +sets P-states or C-states on metal. Filed so the placement track (see `placement-is-blind-to-caches-and-topology.md`) leaves room for an idle-state input when it designs wake placement. From 633203b433f0d6d9f38babf36d0c4e10655f9bc0 Mon Sep 17 00:00:00 2001 From: japabu Date: Sat, 3 Oct 2026 08:52:50 +0200 Subject: [PATCH 05/11] issues: the T14 boot shows the LOG fsd's SYS_FSYNC spinning on XHCI MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The scout's window trails (kernel.log, `scout: win` lines) carry the LOG fsd's SYS_FSYNC after 15 of its windows; in 7 the next event is a contended `lock(src/drivers/xhci/mod.rs:1689 …)`, which at c59e09ed6 is `with_disk_by`'s `XHCI.lock()`. The instrument records a lock only when it spins (scout.patch, SpinWatch: "A contended `Lock::lock`'s look at its own spin"), so the other 8 say nothing either way. No window of 2 ms or more opened at syscall 15. Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_013UDZQ6fSKw14e4w2TKTRfm --- issues/hardware/xhci-waits-are-spins.md | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/issues/hardware/xhci-waits-are-spins.md b/issues/hardware/xhci-waits-are-spins.md index f7291b4d0fe..24383270dda 100644 --- a/issues/hardware/xhci-waits-are-spins.md +++ b/issues/hardware/xhci-waits-are-spins.md @@ -72,7 +72,8 @@ fsd. - **init's partition claims**: on cpu0, 6,002,063 ns at 1.171 s and 6,623,907 ns at 1.179 s, each `SYS_DEVICE_CLAIM` from entry to return, all four samples in `wait_transfer` under `storage_read`. -- **No `SYS_FSYNC`** of that fsd's held interrupts off for 2 ms. +- **Its `SYS_FSYNC`**: 15 windows' trails carry one, and in 7 it spins on a + contended `XHCI` at `with_disk_by`. None held interrupts off for 2 ms. - **Not the firmware**: `MSR_SMI_COUNT` does not move across any of them. The windows it does move across are `issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md`'s. From 995b368f6b4434a393cb6abe793a6b1d9cabccf3 Mon Sep 17 00:00:00 2001 From: japabu Date: Sat, 3 Oct 2026 08:53:34 +0200 Subject: [PATCH 06/11] issues: cite the fsync trails quoted on #681 Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_013UDZQ6fSKw14e4w2TKTRfm --- issues/hardware/xhci-waits-are-spins.md | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/issues/hardware/xhci-waits-are-spins.md b/issues/hardware/xhci-waits-are-spins.md index 24383270dda..d13c2c735a4 100644 --- a/issues/hardware/xhci-waits-are-spins.md +++ b/issues/hardware/xhci-waits-are-spins.md @@ -73,7 +73,8 @@ fsd. 6,623,907 ns at 1.179 s, each `SYS_DEVICE_CLAIM` from entry to return, all four samples in `wait_transfer` under `storage_read`. - **Its `SYS_FSYNC`**: 15 windows' trails carry one, and in 7 it spins on a - contended `XHCI` at `with_disk_by`. None held interrupts off for 2 ms. + contended `XHCI` at `with_disk_by` (comment 5966523482). None held + interrupts off for 2 ms. - **Not the firmware**: `MSR_SMI_COUNT` does not move across any of them. The windows it does move across are `issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md`'s. From 18335e5b1295b30c88287d60f8a7778c886c130f Mon Sep 17 00:00:00 2001 From: japabu Date: Sat, 3 Oct 2026 09:19:31 +0200 Subject: [PATCH 07/11] issues: the PCI claim's exit bounds its longest masked window, the firmware's spans two periods, and the missing AML interpreter has a file Round 3 of #681's review. - The PCI claim's exit bounded the syscall from entry to return at 223 us, from the enumeration's reads of absent functions on buses no bridge decodes, a population the claim never reads: it reads 24 present functions, and its one reading is 159 us a read. A fix in the owner's stage 5 shape opens interrupts between those reads, closes the title's defect, and would still have failed that bound. The exit now bounds the longest interrupts-off window inside the claim at one register access, with MSR_SMI_COUNT unmoved across it; that access's figure comes from the claim's own reads timed on the T14, which nobody has timed. The enumeration-rate derivation goes. - The firmware issue's exit had no minimum interval: two readings closer than one 2.2 s period agree with nothing fixed. The interval now spans at least 4.444 s, twice the longest period read (2,221,576,672 ns). - No file recorded that ToyOS interprets no AML, and the two tracks that wait on it pointed at each other for it. New issues/kernel/toyos-interprets-no-aml.md says what is missing and who waits; both lines point at it. Filing it starts no work. Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_013UDZQ6fSKw14e4w2TKTRfm --- ...terrupts-every-cpu-every-2-2-s-under-toyos.md | 7 ++++--- .../idle-cpus-enter-the-c-states-cst-names.md | 4 ++-- ...-t14-lacks-holds-interrupts-off-for-3-8-ms.md | 15 ++++----------- .../the-scheduler-and-the-clocks-never-talk.md | 8 ++++---- issues/kernel/toyos-interprets-no-aml.md | 16 ++++++++++++++++ 5 files changed, 30 insertions(+), 20 deletions(-) create mode 100644 issues/kernel/toyos-interprets-no-aml.md diff --git a/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md b/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md index e6144114283..50052a73baf 100644 --- a/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md +++ b/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md @@ -60,6 +60,7 @@ scout's result. **Exit**: a T14 row reads `MSR_SMI_COUNT` on every CPU after init is spawned and after the boot's last write to `SMI_CMD`, whoever makes it, and again at -the stop's report, and on every CPU the two agree. The interval opens after -that write because the ACPI enable is one, a write of `ACPI_ENABLE` to -`SMI_CMD`, and raises one firmware interrupt where `APMC_EN` is set. +the stop's report at least 4.444 s later, two of the longest period read, and +on every CPU the two agree. The interval opens after that write because the +ACPI enable is one, a write of `ACPI_ENABLE` to `SMI_CMD`, and raises one +firmware interrupt where `APMC_EN` is set. diff --git a/issues/kernel/idle-cpus-enter-the-c-states-cst-names.md b/issues/kernel/idle-cpus-enter-the-c-states-cst-names.md index ea53ca33f83..352f78dffce 100644 --- a/issues/kernel/idle-cpus-enter-the-c-states-cst-names.md +++ b/issues/kernel/idle-cpus-enter-the-c-states-cst-names.md @@ -7,8 +7,8 @@ opened: 2026-09-29 # Idle CPUs enter the C-states `_CST` names The kernel runs no `mwait` and reads no `_CST`. The states come from `_CST`, -as Linux takes the T14's, after the AML interpreter that -`issues/kernel/the-scheduler-and-the-clocks-never-talk.md` waits on. +as Linux takes the T14's, after the AML interpreter +`issues/kernel/toyos-interprets-no-aml.md` records ToyOS lacks. **Exit**: on the T14, since a KVM guest's idle is its host's: the idle minute's package energy, and timer lateness no worse than `hlt`'s by more than diff --git a/issues/kernel/inits-claim-of-a-pci-function-the-t14-lacks-holds-interrupts-off-for-3-8-ms.md b/issues/kernel/inits-claim-of-a-pci-function-the-t14-lacks-holds-interrupts-off-for-3-8-ms.md index 6d892e51287..b1e84d61685 100644 --- a/issues/kernel/inits-claim-of-a-pci-function-the-t14-lacks-holds-interrupts-off-for-3-8-ms.md +++ b/issues/kernel/inits-claim-of-a-pci-function-the-t14-lacks-holds-interrupts-off-for-3-8-ms.md @@ -26,14 +26,7 @@ have left the kernel. whose stage 5 exits on no interrupts-off window longer than a register access, and whose step 10 takes the partition claims off cpu0. -**Exit**: a T14 boot reads that claim's window, from the syscall's entry to -its return, under 223 µs, with `MSR_SMI_COUNT` unmoved across it. The bound -is an estimate: the claim's 24 vendor-ID reads at 9.3 µs each, the most a -read averaged over the last 7,871 or more of the same boot's enumeration, all -of absent functions, between `PCI 0a:00.0` at 0.072 s and `Enumeration -complete` at 0.144 s: at most 73 ms on stamps of whole milliseconds (#681, -comment 5966492598). Not every read was that fast: the 31 to 38 absent functions -behind `00:1c.4`, between `PCI 09:00.0` at 0.068 s and `PCI 0a:00.0`, took 3 -to 5 ms, about 80 to 160 µs a read, and 3,817,265 ns is 159 µs for each of -the claim's 24. A claim whose reads cost that clears this bound only by making -fewer. +**Exit**: a T14 boot reads the longest interrupts-off window inside that +claim no longer than one register access, with `MSR_SMI_COUNT` unmoved across +that window. A figure for that access comes from the claim's own reads timed +on the T14, and nobody has timed them yet. diff --git a/issues/kernel/the-scheduler-and-the-clocks-never-talk.md b/issues/kernel/the-scheduler-and-the-clocks-never-talk.md index 7c3b9ac3917..64cb0da99f1 100644 --- a/issues/kernel/the-scheduler-and-the-clocks-never-talk.md +++ b/issues/kernel/the-scheduler-and-the-clocks-never-talk.md @@ -19,7 +19,7 @@ Two couplings every production scheduler has and ours lacks: wake. A latency-sensitive wake should prefer a shallow-idle core; a throughput task can pay to wake a deep one. -Both wait for an AML interpreter, because today the kernel neither reads nor -sets P-states or C-states on metal. Filed so the placement track (see -`placement-is-blind-to-caches-and-topology.md`) leaves room for an idle-state -input when it designs wake placement. +Both wait for an AML interpreter (`issues/kernel/toyos-interprets-no-aml.md`), +because today the kernel neither reads nor sets P-states or C-states on metal. +Filed so the placement track (see `placement-is-blind-to-caches-and-topology.md`) +leaves room for an idle-state input when it designs wake placement. diff --git a/issues/kernel/toyos-interprets-no-aml.md b/issues/kernel/toyos-interprets-no-aml.md new file mode 100644 index 00000000000..ddac020dcf5 --- /dev/null +++ b/issues/kernel/toyos-interprets-no-aml.md @@ -0,0 +1,16 @@ +--- +status: open +kind: track +opened: 2026-10-03 +--- + +# ToyOS interprets no AML + +Nothing in the tree evaluates the AML in a machine's DSDT or SSDTs. What +ToyOS takes from them it takes another way: `toyos-acpi/src/dsdt.rs` finds +`\_S5_` by a byte scan, and the loader asks UEFI for the root bridges' +windows `_CRS` would name (`bootloader/src/rootbridge.rs`). Nothing reads +`_CST`, which names a CPU's C-states. + +Two tracks wait on it: `issues/kernel/the-scheduler-and-the-clocks-never-talk.md` +and `issues/kernel/idle-cpus-enter-the-c-states-cst-names.md`. From e4640ca4dd2f92d84d016365848893a9b7dceb40 Mon Sep 17 00:00:00 2001 From: japabu Date: Sat, 3 Oct 2026 09:33:19 +0200 Subject: [PATCH 08/11] issues: the AML track carries the owner's direction, and drops its list of who waits The owner's line "own AML interpreter, battery first" sat in issues/kernel/the-scheduler-and-the-clocks-never-talk.md beside the false "task #136" label until 995b368f6 removed both. It came from the 2026-08-16 direction conversation that 0ee814f5a records, and the AML track is now its home: without it the next agent could take a third-party interpreter or start from _CST against a recorded direction. The "Two tracks wait on it" line goes: git grep answers who waits, and the count was already short (the touchpad's GpioInt is a _CRS descriptor, and HID over I2C takes its descriptor address from _DSM). Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_013UDZQ6fSKw14e4w2TKTRfm --- issues/kernel/toyos-interprets-no-aml.md | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/issues/kernel/toyos-interprets-no-aml.md b/issues/kernel/toyos-interprets-no-aml.md index ddac020dcf5..3434d68fcea 100644 --- a/issues/kernel/toyos-interprets-no-aml.md +++ b/issues/kernel/toyos-interprets-no-aml.md @@ -12,5 +12,5 @@ ToyOS takes from them it takes another way: `toyos-acpi/src/dsdt.rs` finds windows `_CRS` would name (`bootloader/src/rootbridge.rs`). Nothing reads `_CST`, which names a CPU's C-states. -Two tracks wait on it: `issues/kernel/the-scheduler-and-the-clocks-never-talk.md` -and `issues/kernel/idle-cpus-enter-the-c-states-cst-names.md`. +The owner's direction, recorded in `0ee814f5a`: ToyOS writes its own AML +interpreter, and the battery comes first. From 0f76470c19b3dd6a3b473c0cecf1d16b9997a187 Mon Sep 17 00:00:00 2001 From: japabu Date: Sat, 3 Oct 2026 09:38:05 +0200 Subject: [PATCH 09/11] issues: the T14's firmware interrupt is its legacy mode, measured The orchestrator's scout on the owner's go (comment 5966817345 on #681) booted main at 73282fa93 on the T14 twice, each boot 30 s idle then 30 s with a spinning thread per CPU. With nothing written the firmware leaves the machine in legacy mode (PM1a_CNT 0x0000, SCI_EN clear, all boot) and MSR_SMI_COUNT rises once every 2.2 s, idle and busy alike, 27 in 60 s. With ACPI_ENABLE written to SMI_CMD, SCI_EN reads set 2.13 ms later, the write costs one firmware interrupt, and the count then stays flat on every CPU for 61 s. That replaces "neither SCI_EN nor SMI_EN has been read" and "the cause is not known". Who owns the fix is still the owner's to rule. Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_013UDZQ6fSKw14e4w2TKTRfm --- ...rupts-every-cpu-every-2-2-s-under-toyos.md | 23 +++++++++++++------ 1 file changed, 16 insertions(+), 7 deletions(-) diff --git a/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md b/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md index 50052a73baf..dc2961b2d47 100644 --- a/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md +++ b/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md @@ -44,19 +44,28 @@ What differs, as far as anything has read: `SMI_CMD=0xb2` and `ACPI_ENABLE=0xf0`; `PM1a_CNT` (port 0x1804) `0x0001`, `SCI_EN` set; `SMI_EN` (port 0x1830) `0x10002033`, bits 0 (`GBL_SMI_EN`), 1 (`EOS`), 4 (`SLP_SMI_EN`), 5 (`APMC_EN`), 13 (`TCO_EN`) and 28. -- Under ToyOS neither `SCI_EN` nor `SMI_EN` has been read. -The cause is not known. The `mask-windows` kernel prints such a window as its -CPU's own: cpu4's 4,720,498 ns in the sixth of #649's `mask_windows` boots at -`72f16e39a`, and cpu0's 4,725,822 in `649-r6/3-idle-halt-counted` +**The cause, measured, is the firmware's legacy mode.** A scout on `main` at +`73282fa93` (comment 5966817345) booted the T14 twice, each boot 30 s idle and +then 30 s with a spinning thread on every CPU: + +- With nothing written, `PM1a_CNT` read `0x0000`, `SCI_EN` clear, from 0.156 s + to 61.226 s, and `SMI_EN` read `0x10002033`, Linux's value. The count rose + by 14 in the idle 30 s and 13 in the busy 30 s, on every CPU alike. +- With `ACPI_ENABLE` written to `SMI_CMD` at 0.156 s, `SCI_EN` read set + 2,129,279 ns later. The write moved the writing CPU's count from 4817 to + 4818, and every CPU then read 4818 at every report through 61.233 s. The + SCI's line, GSI 9, stayed masked: nothing in ToyOS handles an SCI. + +The `mask-windows` kernel prints such a window as its CPU's own: cpu4's +4,720,498 ns in the sixth of #649's `mask_windows` boots at `72f16e39a`, and cpu0's 4,725,822 in `649-r6/3-idle-halt-counted` (`issues/kernel/a-process-lengthens-an-interrupts-off-walk-by-the-threads-it-parks-on-one-ring.md`), are this by reading, those kernels not reading the count. **Owner**: the T14 loop (`issues/hardware/the-t14-boots-toyos-unattended.md`) owns only the reading: its jobs are the measurements owed on hardware, and it -builds the row. The fix has no owner in the tree yet: the owner has approved a -scout of the switch to ACPI mode, and who owns a fix is put to him with the -scout's result. +builds the row. The fix has no owner in the tree yet: who owns it is put to +the owner with the scout's result. **Exit**: a T14 row reads `MSR_SMI_COUNT` on every CPU after init is spawned and after the boot's last write to `SMI_CMD`, whoever makes it, and again at From f85f659f45d6da021be8c06f082eb53bfe5fc95b Mon Sep 17 00:00:00 2001 From: japabu Date: Sat, 3 Oct 2026 09:47:23 +0200 Subject: [PATCH 10/11] issues: the ACPI track takes the owner's ruling, its stage 1 the T14's firmware fix The owner ruled on the firmware scout (#681, comment 5966817345): the ACPI enable lands as the first stage of the ACPI track, together with a userland server that claims the SCI and handles the power button, a fixed event that needs no AML, so nothing the firmware does in legacy mode today is lost. The AML interpreter, battery first (his direction of 0ee814f5a), follows as later stages. He chose this over landing the write alone with the events masked, and over waiting for the AML work. toyos-interprets-no-aml no longer says what the track is, so it becomes toyos-runs-the-machine-in-acpi-mode-and-interprets-its-aml, keeps its opened date and stays an open track. Its two citations move with it. The firmware issue's fix is owned by that track's stage 1; its exit is stage 1's first half. Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_013UDZQ6fSKw14e4w2TKTRfm --- ...rupts-every-cpu-every-2-2-s-under-toyos.md | 9 +++--- .../idle-cpus-enter-the-c-states-cst-names.md | 3 +- ...the-scheduler-and-the-clocks-never-talk.md | 3 +- issues/kernel/toyos-interprets-no-aml.md | 16 ---------- ...ine-in-acpi-mode-and-interprets-its-aml.md | 31 +++++++++++++++++++ 5 files changed, 40 insertions(+), 22 deletions(-) delete mode 100644 issues/kernel/toyos-interprets-no-aml.md create mode 100644 issues/kernel/toyos-runs-the-machine-in-acpi-mode-and-interprets-its-aml.md diff --git a/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md b/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md index dc2961b2d47..77cae05b2f8 100644 --- a/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md +++ b/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md @@ -62,10 +62,11 @@ The `mask-windows` kernel prints such a window as its CPU's own: cpu4's (`issues/kernel/a-process-lengthens-an-interrupts-off-walk-by-the-threads-it-parks-on-one-ring.md`), are this by reading, those kernels not reading the count. -**Owner**: the T14 loop (`issues/hardware/the-t14-boots-toyos-unattended.md`) -owns only the reading: its jobs are the measurements owed on hardware, and it -builds the row. The fix has no owner in the tree yet: who owns it is put to -the owner with the scout's result. +**Owner**: the fix is stage 1 of +`issues/kernel/toyos-runs-the-machine-in-acpi-mode-and-interprets-its-aml.md`. +The T14 loop (`issues/hardware/the-t14-boots-toyos-unattended.md`) owns only +the reading: its jobs are the measurements owed on hardware, and it builds the +row. **Exit**: a T14 row reads `MSR_SMI_COUNT` on every CPU after init is spawned and after the boot's last write to `SMI_CMD`, whoever makes it, and again at diff --git a/issues/kernel/idle-cpus-enter-the-c-states-cst-names.md b/issues/kernel/idle-cpus-enter-the-c-states-cst-names.md index 352f78dffce..fda05c16c34 100644 --- a/issues/kernel/idle-cpus-enter-the-c-states-cst-names.md +++ b/issues/kernel/idle-cpus-enter-the-c-states-cst-names.md @@ -8,7 +8,8 @@ opened: 2026-09-29 The kernel runs no `mwait` and reads no `_CST`. The states come from `_CST`, as Linux takes the T14's, after the AML interpreter -`issues/kernel/toyos-interprets-no-aml.md` records ToyOS lacks. +`issues/kernel/toyos-runs-the-machine-in-acpi-mode-and-interprets-its-aml.md` +records ToyOS lacks. **Exit**: on the T14, since a KVM guest's idle is its host's: the idle minute's package energy, and timer lateness no worse than `hlt`'s by more than diff --git a/issues/kernel/the-scheduler-and-the-clocks-never-talk.md b/issues/kernel/the-scheduler-and-the-clocks-never-talk.md index 64cb0da99f1..c9a9165e011 100644 --- a/issues/kernel/the-scheduler-and-the-clocks-never-talk.md +++ b/issues/kernel/the-scheduler-and-the-clocks-never-talk.md @@ -19,7 +19,8 @@ Two couplings every production scheduler has and ours lacks: wake. A latency-sensitive wake should prefer a shallow-idle core; a throughput task can pay to wake a deep one. -Both wait for an AML interpreter (`issues/kernel/toyos-interprets-no-aml.md`), +Both wait for an AML interpreter +(`issues/kernel/toyos-runs-the-machine-in-acpi-mode-and-interprets-its-aml.md`), because today the kernel neither reads nor sets P-states or C-states on metal. Filed so the placement track (see `placement-is-blind-to-caches-and-topology.md`) leaves room for an idle-state input when it designs wake placement. diff --git a/issues/kernel/toyos-interprets-no-aml.md b/issues/kernel/toyos-interprets-no-aml.md deleted file mode 100644 index 3434d68fcea..00000000000 --- a/issues/kernel/toyos-interprets-no-aml.md +++ /dev/null @@ -1,16 +0,0 @@ ---- -status: open -kind: track -opened: 2026-10-03 ---- - -# ToyOS interprets no AML - -Nothing in the tree evaluates the AML in a machine's DSDT or SSDTs. What -ToyOS takes from them it takes another way: `toyos-acpi/src/dsdt.rs` finds -`\_S5_` by a byte scan, and the loader asks UEFI for the root bridges' -windows `_CRS` would name (`bootloader/src/rootbridge.rs`). Nothing reads -`_CST`, which names a CPU's C-states. - -The owner's direction, recorded in `0ee814f5a`: ToyOS writes its own AML -interpreter, and the battery comes first. diff --git a/issues/kernel/toyos-runs-the-machine-in-acpi-mode-and-interprets-its-aml.md b/issues/kernel/toyos-runs-the-machine-in-acpi-mode-and-interprets-its-aml.md new file mode 100644 index 00000000000..54d05a838d5 --- /dev/null +++ b/issues/kernel/toyos-runs-the-machine-in-acpi-mode-and-interprets-its-aml.md @@ -0,0 +1,31 @@ +--- +status: open +kind: track +opened: 2026-10-03 +--- + +# ToyOS runs the machine in ACPI mode and interprets its AML + +ToyOS leaves the machine in the mode its firmware hands over: nothing writes +`ACPI_ENABLE` to `SMI_CMD`, and nothing handles an SCI. The T14's firmware +hands it over in legacy mode, which interrupts every CPU every 2.2 s +(`issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md`). + +Nothing in the tree evaluates the AML in a machine's DSDT or SSDTs. What +ToyOS takes from them it takes another way: `toyos-acpi/src/dsdt.rs` finds +`\_S5_` by a byte scan, and the loader asks UEFI for the root bridges' +windows `_CRS` would name (`bootloader/src/rootbridge.rs`). Nothing reads +`_CST`, which names a CPU's C-states. + +**Ruled** (owner, 2026-10-03, on the scout in #681's comment 5966817345): the +switch to ACPI mode lands as stage 1, with its events served in userland, so +nothing the firmware does in legacy mode today is lost; not the switch alone +with the events masked, and not after the AML work. The AML interpreter +follows as later stages: ToyOS writes its own, and the battery comes first +(his direction of `0ee814f5a`). + +**Stage 1: ACPI mode, its SCI served in userland.** The switch to ACPI mode, +and a userland server that claims the SCI and handles the power button, a +fixed event that needs no AML. **Exit**: on the T14, `MSR_SMI_COUNT` stays +flat on every CPU over the interval the firmware issue's exit defines, and a +press of the power button is handled. From dfa31c8a9bf9a26a7984a6365482957cd84e0861 Mon Sep 17 00:00:00 2001 From: japabu Date: Sat, 3 Oct 2026 10:03:12 +0200 Subject: [PATCH 11/11] issues: the ACPI track states the ruling as drawn, its stage 1 exit names what a press does, and the firmware issue records the two GPEs the switch moved The track's ruling said stage 1 lands "with its events served in userland", which claims more than the owner ruled: he ruled a userland server that claims the SCI and handles the power button, and the ruling now says that. Stage 1's exit said a press of the power button "is handled", which names nothing a row can read. It now names what the ruling implies: the press stops the machine cleanly through ToyOS's own power-off path, SYS_SHUTDOWN, and the boot's log records the press and that stop, which is where a T14 row reads it. The firmware issue's ACPI_ENABLE bullet now records the two GPE readings the boot carried, read from its kernel.log lines quoted whole on #681 (comment 5966982752; the other boot's in 5966982609, the patch in 5966982939): the firmware's enable set GPE 9's enable bit (gpe0_en byte 1, 00 at line 121, 02 at line 123), and GPE 110's status rose after the switch and stayed set, served by nothing (gpe0_sts byte 13, 40 from line 298 through line 759, in none of the other boot's 25 reports). Stage 1's server meets both once it unmasks GSI 9. Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_013UDZQ6fSKw14e4w2TKTRfm --- ...interrupts-every-cpu-every-2-2-s-under-toyos.md | 11 ++++++++++- ...-machine-in-acpi-mode-and-interprets-its-aml.md | 14 ++++++++------ 2 files changed, 18 insertions(+), 7 deletions(-) diff --git a/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md b/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md index 77cae05b2f8..04874b9c582 100644 --- a/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md +++ b/issues/hardware/the-t14s-firmware-interrupts-every-cpu-every-2-2-s-under-toyos.md @@ -55,7 +55,16 @@ then 30 s with a spinning thread on every CPU: - With `ACPI_ENABLE` written to `SMI_CMD` at 0.156 s, `SCI_EN` read set 2,129,279 ns later. The write moved the writing CPU's count from 4817 to 4818, and every CPU then read 4818 at every report through 61.233 s. The - SCI's line, GSI 9, stayed masked: nothing in ToyOS handles an SCI. + SCI's line, GSI 9, stayed masked: nothing in ToyOS handles an SCI. Two GPEs + moved after the switch, in that boot's `kernel.log` lines quoted in comment + 5966982752 (the patch, comment 5966982939, prints each GPE register byte by + byte, lowest address first): + - the firmware's enable set GPE 9's enable bit: `gpe0_en` byte 1 reads `00` + at line 121, before the write, and `02` at line 123, after it; + - GPE 110's status rose after the switch and stayed set, served by nothing: + `gpe0_sts` byte 13 reads `00` at line 123 and `40` at every report from + line 298 through line 759. The boot with nothing written shows it in none + of its 25 reports (comment 5966982609). The `mask-windows` kernel prints such a window as its CPU's own: cpu4's 4,720,498 ns in the sixth of #649's `mask_windows` boots at `72f16e39a`, and cpu0's 4,725,822 in `649-r6/3-idle-halt-counted` diff --git a/issues/kernel/toyos-runs-the-machine-in-acpi-mode-and-interprets-its-aml.md b/issues/kernel/toyos-runs-the-machine-in-acpi-mode-and-interprets-its-aml.md index 54d05a838d5..75a57722416 100644 --- a/issues/kernel/toyos-runs-the-machine-in-acpi-mode-and-interprets-its-aml.md +++ b/issues/kernel/toyos-runs-the-machine-in-acpi-mode-and-interprets-its-aml.md @@ -18,14 +18,16 @@ windows `_CRS` would name (`bootloader/src/rootbridge.rs`). Nothing reads `_CST`, which names a CPU's C-states. **Ruled** (owner, 2026-10-03, on the scout in #681's comment 5966817345): the -switch to ACPI mode lands as stage 1, with its events served in userland, so -nothing the firmware does in legacy mode today is lost; not the switch alone -with the events masked, and not after the AML work. The AML interpreter -follows as later stages: ToyOS writes its own, and the battery comes first -(his direction of `0ee814f5a`). +switch to ACPI mode lands as stage 1, together with a userland server that +claims the SCI and handles the power button, so nothing the firmware does in +legacy mode today is lost; not the switch alone with the events masked, and +not after the AML work. The AML interpreter follows as later stages: ToyOS +writes its own, and the battery comes first (his direction of `0ee814f5a`). **Stage 1: ACPI mode, its SCI served in userland.** The switch to ACPI mode, and a userland server that claims the SCI and handles the power button, a fixed event that needs no AML. **Exit**: on the T14, `MSR_SMI_COUNT` stays flat on every CPU over the interval the firmware issue's exit defines, and a -press of the power button is handled. +press of the power button stops the machine cleanly, through ToyOS's own +power-off path (`SYS_SHUTDOWN`), and the boot's log records the press and that +stop: a T14 row reads both there.