From 38d28863e0599263e915b60568787d93e6c773f8 Mon Sep 17 00:00:00 2001 From: japabu Date: Thu, 1 Oct 2026 04:03:42 +0200 Subject: [PATCH 1/4] AArch64 stage 4: the boot-timing handoff names the CPU's counter, and virt judges it Closes issues/kernel/the-boot-timing-handoff-is-named-for-the-tsc.md, the stage-4 item that waited on an ABI brief; the owner's ruling that the ABI is completely unstable lifts that wait. KernelArgs carried loader_entry_tsc, loader_handoff_tsc and root_read_tsc, and the kernel's report said "the TSC went backwards". On AArch64 both loaders' readings come from arch::counter, CNTVCT_EL0 there, so the ABI and the report named a counter the machine does not have. - toyos-abi: the fields are loader_entry_counter, loader_handoff_counter (readings of the CPU's counter) and root_read_ticks (a span in its ticks). Same offsets; the offset_of! asserts still hold them. - The loader: its tsc() wrapper, whose doc said the counter "counts from reset", goes; every reading calls arch::counter. Its lines say "Loader counter:" and "counter ticks". src/kernelconsole.rs's fixture of the ROOT read line follows. - The kernel: report_power_on says "the counter went backwards". - tests: boot_from_power_on takes the guest's Arch and reads the rate off that architecture's clock record: x86-64's TSC period, AArch64's CNTFRQ_EL0 rate divided into a second as the kernel divides it. A "counter went backwards" line is its own refusal. virt_boot_from_power_on (VirtEl2) runs the same judge on AArch64, where the loader reads the generic timer at EL2 and both binaries speak on the PL011. Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_016t9wjdQkB8SH7bmfUoiy6L --- bootloader/src/main.rs | 27 ++++---- bootloader/src/rootimage.rs | 16 ++--- bootloader/src/slot.rs | 4 +- ...oes-only-what-must-precede-the-handover.md | 2 +- .../portable-kernel-code-names-the-tsc.md | 2 - ...oot-timing-handoff-is-named-for-the-tsc.md | 21 ------- issues/kernel/toyos-runs-on-arm64.md | 4 +- kernel/src/main.rs | 16 ++--- src/kernelconsole.rs | 2 +- tests/toyos.rs | 63 +++++++++++++++---- toyos-abi/src/boot.rs | 26 ++++---- 11 files changed, 95 insertions(+), 88 deletions(-) delete mode 100644 issues/kernel/the-boot-timing-handoff-is-named-for-the-tsc.md diff --git a/bootloader/src/main.rs b/bootloader/src/main.rs index b2b607b6714..a49c0663f04 100644 --- a/bootloader/src/main.rs +++ b/bootloader/src/main.rs @@ -513,13 +513,8 @@ fn report_reach(what: &str, at: u64, len: u64) { ); } -/// The CPU's free-running counter, which counts from reset. -fn tsc() -> u64 { - arch::counter() -} - #[allow(clippy::too_many_arguments)] -fn start_kernel(kernel: LoadedKernel, kernel_elf_bytes: vec::Vec, cmdline: vec::Vec, rsdp_addr: u64, gop: Option, boot_part: Option, log_partition_guid: [u8; 16], layout: u32, root_image: Option, entry_tsc: u64, system_table: SystemTable) -> ! { +fn start_kernel(kernel: LoadedKernel, kernel_elf_bytes: vec::Vec, cmdline: vec::Vec, rsdp_addr: u64, gop: Option, boot_part: Option, log_partition_guid: [u8; 16], layout: u32, root_image: Option, entry_counter: u64, system_table: SystemTable) -> ! { // Said before it is refused, for `report_reach`'s reason. match arch::cpu_as_entered() { Ok(None) => {} @@ -612,7 +607,7 @@ fn start_kernel(kernel: LoadedKernel, kernel_elf_bytes: vec::Vec, cmdline: v None => ([0u8; 16], 0, 0, 0), }; - let (root_image_addr, root_image_len, root_partition_guid, root_read_tsc) = + let (root_image_addr, root_image_len, root_partition_guid, root_read_ticks) = root_image.as_ref().map_or((0, 0, [0; 16], 0), rootimage::RootImage::handoff); // Built before the exit so the address the kernel is handed is one this @@ -649,9 +644,9 @@ fn start_kernel(kernel: LoadedKernel, kernel_elf_bytes: vec::Vec, cmdline: v root_image_addr, root_image_len, root_partition_guid, - loader_entry_tsc: entry_tsc, - loader_handoff_tsc: 0, - root_read_tsc, + loader_entry_counter: entry_counter, + loader_handoff_counter: 0, + root_read_ticks, }; report_reach( "Kernel arguments", @@ -659,10 +654,10 @@ fn start_kernel(kernel: LoadedKernel, kernel_elf_bytes: vec::Vec, cmdline: v mem::size_of::() as u64, ); - kernel_args.loader_handoff_tsc = tsc(); + kernel_args.loader_handoff_counter = arch::counter(); println!( - "Loader TSC: {entry_tsc} at entry, {} at the handoff", - kernel_args.loader_handoff_tsc, + "Loader counter: {entry_counter} at entry, {} at the handoff", + kernel_args.loader_handoff_counter, ); // Last, and after every line above: a console write, a FAT write and a @@ -766,8 +761,8 @@ fn end_this_pass(system_table: &SystemTable, exit_event: Option) -> #[entry] fn main(handle: Handle, mut system_table: SystemTable) -> Status { - // First: the TSC counts from reset, so this is what firmware took. - let entry_tsc = tsc(); + // First, so this reading is firmware's time and none of the loader's. + let entry_counter = arch::counter(); let exit_event = uefi_services::init(&mut system_table).unwrap(); // First, because it covers everything below it: firmware starts a // five-minute countdown when it loads an image and resets the machine if @@ -992,5 +987,5 @@ fn main(handle: Handle, mut system_table: SystemTable) -> Status { watchdog::arm(&system_table, rsdp_addr, params); println!("Starting kernel..."); - start_kernel(loaded_kernel, kernel_bytes, cmdline, rsdp_addr, gop, boot_part, log_guid, layout, root_image, entry_tsc, system_table); + start_kernel(loaded_kernel, kernel_bytes, cmdline, rsdp_addr, gop, boot_part, log_guid, layout, root_image, entry_counter, system_table); } diff --git a/bootloader/src/rootimage.rs b/bootloader/src/rootimage.rs index 3609e088bab..2d33396f7da 100644 --- a/bootloader/src/rootimage.rs +++ b/bootloader/src/rootimage.rs @@ -58,15 +58,15 @@ pub struct RootImage { len: u64, /// The partition it was read from, raw as in its GPT entry. partition: [u8; 16], - /// The TSC cycles the read took. - cycles: u64, + /// The counter ticks the read took. + ticks: u64, } impl RootImage { /// Where the kernel is told the image is, which partition it came from, and - /// the cycles reading it took. + /// the counter ticks reading it took. pub fn handoff(&self) -> (u64, u64, [u8; 16], u64) { - (self.at, self.len, self.partition, self.cycles) + (self.at, self.len, self.partition, self.ticks) } /// The image's bytes, for the hash its slot's header names. @@ -242,10 +242,10 @@ impl<'a> Disk<'a> { // Chunks are whole `BLOCK`s from a page-aligned buffer, so each one // keeps the `IoAlign` `open` checked against `BLOCK`. let chunk = chunk::chunk_bytes(CHUNK_BOUND, BLOCK, self.lba_bytes, granularity.unwrap_or(0)); - let began = crate::tsc(); + let began = crate::arch::counter(); let mut device = Firmware { io: &self.io, media_id: self.media_id }; let read = chunk::read(&mut device, part.first_lba(), self.lba_bytes, chunk, into); - let image = RootImage { at, len, partition: part.unique_guid().0, cycles: crate::tsc().wrapping_sub(began) }; + let image = RootImage { at, len, partition: part.unique_guid().0, ticks: crate::arch::counter().wrapping_sub(began) }; if let Err(failed) = read { let why = alloc::format!( "the read of {} blocks at LBA {} failed: {:?}, after {} of {len} bytes read", @@ -258,14 +258,14 @@ impl<'a> Disk<'a> { return Err(why); } println!( - "{READ_AT} {at:#x}+{len:#x} from LBA {}+{}, {chunk} bytes a request (optimal granularity: {}), in {} TSC cycles", + "{READ_AT} {at:#x}+{len:#x} from LBA {}+{}, {chunk} bytes a request (optimal granularity: {}), in {} counter ticks", part.first_lba(), len / u64::from(self.lba_bytes), match granularity { Some(lbas) => alloc::format!("{lbas} block(s)"), None => String::from("not reported"), }, - image.cycles + image.ticks ); Ok(image) } diff --git a/bootloader/src/slot.rs b/bootloader/src/slot.rs index 424bcfe8764..954ed7e4612 100644 --- a/bootloader/src/slot.rs +++ b/bootloader/src/slot.rs @@ -145,9 +145,9 @@ fn verify( println!("{HEAD} {letter}: ROOT: {why}"); Refusal::Unreadable("root") })?; - let began = crate::tsc(); + let began = crate::arch::counter(); let root_hash = toyos_update::sha256(root.bytes()); - println!("{HEAD} {letter}: ROOT hashed in {} TSC cycles", crate::tsc().wrapping_sub(began)); + println!("{HEAD} {letter}: ROOT hashed in {} counter ticks", crate::arch::counter().wrapping_sub(began)); if root_hash != header.root().sha256 { root.free(bs); return Err(Refusal::Hash("root")); diff --git a/issues/boot-media/the-loader-does-only-what-must-precede-the-handover.md b/issues/boot-media/the-loader-does-only-what-must-precede-the-handover.md index 9ae21c395e8..27f7ad3f5f6 100644 --- a/issues/boot-media/the-loader-does-only-what-must-precede-the-handover.md +++ b/issues/boot-media/the-loader-does-only-what-must-precede-the-handover.md @@ -186,7 +186,7 @@ Each stage lands on its own, in this order. `kernel_args_last_layout_refused` boots with `loader-writes-the-last-layout` and finds the kernel's refusal naming both words before any `black box:` record. Moving `layout` after - `root_read_tsc` fails to build, and so does padding `KernelArgs` back to + `root_read_ticks` fails to build, and so does padding `KernelArgs` back to 1272 bytes: `size_of::()` is then stage 1's size again, the derived `LAYOUT` collapses onto the literal `LAST_LAYOUT` (`0x5459_0000 | 1272`), and `assert!(LAYOUT != LAST_LAYOUT)` fails the diff --git a/issues/kernel/portable-kernel-code-names-the-tsc.md b/issues/kernel/portable-kernel-code-names-the-tsc.md index d2c1ea18d5d..251f599c86c 100644 --- a/issues/kernel/portable-kernel-code-names-the-tsc.md +++ b/issues/kernel/portable-kernel-code-names-the-tsc.md @@ -12,8 +12,6 @@ portable kernel still calls it the TSC: `kernel/src/clock.rs`'s `AT_TSC`, and the xHCI driver's, `hardlockup`'s and `panic_reboot`'s waits and comments read it by that name. `clock::counter_ticks`, which the AArch64 timer reads, is renamed; the rest reads as x86-64's on both machines. -`issues/kernel/the-boot-timing-handoff-is-named-for-the-tsc.md` is the ABI's -half of the same name. **Exit condition**: no item or comment outside `kernel/src/arch/x86_64/` names the TSC for the counter `crate::arch::cpu::counter` reads. diff --git a/issues/kernel/the-boot-timing-handoff-is-named-for-the-tsc.md b/issues/kernel/the-boot-timing-handoff-is-named-for-the-tsc.md deleted file mode 100644 index 8da9acbaaed..00000000000 --- a/issues/kernel/the-boot-timing-handoff-is-named-for-the-tsc.md +++ /dev/null @@ -1,21 +0,0 @@ ---- -status: open -kind: defect -opened: 2026-09-26 ---- - -# The boot-timing handoff is named for the TSC - -`toyos-abi/src/boot.rs`'s `KernelArgs` carries `loader_entry_tsc` and -`loader_handoff_tsc`, and `kernel/src/main.rs`'s `report_power_on` reports -"the TSC went backwards". On AArch64 the loader fills both from `CNTVCT_EL0`, -the generic timer's count, so the ABI and the message name a counter the -machine does not have. - -Owned by stage 4 of `issues/kernel/toyos-runs-on-arm64.md`, which makes the -generic timer the clock. `KernelArgs` is the ABI, so the rename lands with -that stage's other ABI work. - -**Exit condition**: the two fields and the report name the CPU's counter -(`cpu::counter`) rather than the TSC, and both architectures' loaders fill -them. diff --git a/issues/kernel/toyos-runs-on-arm64.md b/issues/kernel/toyos-runs-on-arm64.md index 123db6c3868..64ea55d1918 100644 --- a/issues/kernel/toyos-runs-on-arm64.md +++ b/issues/kernel/toyos-runs-on-arm64.md @@ -202,7 +202,6 @@ before any aarch64 file exists, with x86 as its only user: Each is its own issue, owned by the stage that removes it: - `issues/kernel/msi-and-pin-routing-take-an-x86-vector-and-apic-id.md` (stage 6) -- `issues/kernel/the-boot-timing-handoff-is-named-for-the-tsc.md` (stage 4) - `issues/kernel/the-crash-evidence-records-x86-fault-registers.md` (stage 5) - `issues/kernel/the-aarch64-kernel-builds-with-dead-code-allowed.md` (stage 7) @@ -263,8 +262,7 @@ Each stage names its exit; "measured" means a number from a run. exposes no RNDR and the kernel's hash seed refuses there until stage 6's virtio-rng. Each judges an event, never a rate: no QEMU test measures time. Owed before the exit holds: the interrupts-off window against x86's, a - measurement only metal can make, with no instrument on either arch yet; - `issues/kernel/the-boot-timing-handoff-is-named-for-the-tsc.md`; the + measurement only metal can make, with no instrument on either arch yet; the instruction-cache maintenance before a mapping is executable (`cache::make_executable`), the break-before-make ordering of a live entry's replacement, and the TLB flush before a reclaimed ASID is issued diff --git a/kernel/src/main.rs b/kernel/src/main.rs index e91c58580f8..0534567c859 100644 --- a/kernel/src/main.rs +++ b/kernel/src/main.rs @@ -178,15 +178,15 @@ fn register_gpu(driver: Box, info: gpu::GpuInfo) { gpu::register(driver, info); } -/// The boot from power-on, off the loader's TSC readings and `complete`'s, at -/// the calibrated rate. The TSC counts from reset, so the first span is -/// firmware's unless firmware wrote the counter. +/// The boot from power-on, off the loader's [`cpu::counter`] readings and +/// `complete`'s, at the clock's rate. The first span is firmware's time since +/// the counter started. fn report_power_on(args: &KernelArgs, complete: u64) { arch::boot::report_counter_origin(); - let (entry, handoff) = (args.loader_entry_tsc, args.loader_handoff_tsc); + let (entry, handoff) = (args.loader_entry_counter, args.loader_handoff_counter); if handoff < entry || complete < handoff { log!( - "boot: the TSC went backwards: {entry} at the loader's entry, {handoff} at its handoff, \ + "boot: the counter went backwards: {entry} at the loader's entry, {handoff} at its handoff, \ {complete} at Boot: complete" ); return; @@ -196,7 +196,7 @@ fn report_power_on(args: &KernelArgs, complete: u64) { "boot: power-on to loader {} ms, loader {} ms (ROOT read {} ms), kernel to Boot: complete {} ms", ms(entry), ms(handoff - entry), - ms(args.root_read_tsc), + ms(args.root_read_ticks), ms(complete - handoff), ); } @@ -605,9 +605,9 @@ pub(crate) unsafe extern "C" fn kernel_main(kernel_args: &KernelArgs) -> ! { } report_log_destination(); - let complete_tsc = cpu::counter(); + let complete = cpu::counter(); boot_phase!("complete", 0); - report_power_on(kernel_args, complete_tsc); + report_power_on(kernel_args, complete); #[cfg(feature = "boot-actuators")] if actuator::test_late_panic() { diff --git a/src/kernelconsole.rs b/src/kernelconsole.rs index f3c15fbc1bd..e23b8634990 100644 --- a/src/kernelconsole.rs +++ b/src/kernelconsole.rs @@ -57,7 +57,7 @@ mod tests { \"UEFI QEMU QEMU USB HARDDRIVE TOYOS0BOOTSTICK1\" from PciRoot(0x0)/Pci(0x1,0x0)/USB(0x0,0x0)\n\ ToyOS Bootloader 1.0\n\ ROOT: read into memory at 0x7c894000+0x800000 from LBA 212992+16384, 1048576 bytes a request \ - (optimal granularity: not reported), in 22519000 TSC cycles\n\ + (optimal granularity: not reported), in 22519000 counter ticks\n\ Loader log: the kernel handoff begins, so "; const KERNEL: &str = "[kernel 0.000 cpu0 boot] black box: 0x8000000 is this boot's, 16344 bytes \ diff --git a/tests/toyos.rs b/tests/toyos.rs index 52ce975d3e7..663b42d294a 100644 --- a/tests/toyos.rs +++ b/tests/toyos.rs @@ -510,6 +510,7 @@ const SCREEN_TESTS: &[(&str, Sched, qemu::Profile)] = &[ ("virt_early_fault", Sched::Parallel, qemu::Profile::Virt), ("virt_el2_drop", Sched::Parallel, qemu::Profile::VirtEl2), ("virt_user_mode", Sched::Parallel, qemu::Profile::VirtEl2), + ("virt_boot_from_power_on", Sched::Parallel, qemu::Profile::VirtEl2), ("virt_timer_preempts", Sched::Parallel, qemu::Profile::VirtEl2), ("virt_irq_storm", Sched::Parallel, qemu::Profile::VirtEl2), ("virt_timer_floor", Sched::Parallel, qemu::Profile::VirtEl2), @@ -599,7 +600,7 @@ const MACHINE_TESTS: &[(&str, Sched)] = &[ // A loader built to another `KernelArgs` layout is refused by name before // the kernel reads a field the layout could have moved. ("kernel_args_layout_refused", Sched::Parallel), - // The boot from power-on, as the kernel converts the loader's TSC readings: + // The boot from power-on, as the kernel converts the loader's counter readings: // judged against the loader's raw counts and the kernel's own rate. ("boot_from_power_on", Sched::Parallel), ("acpi_table_inventory", Sched::Parallel), @@ -5219,6 +5220,20 @@ fn run_screen_test( } Ok(()) } + "virt_boot_from_power_on" => { + // `boot_from_power_on` where the loader's counter is the generic + // timer's, read at EL2 before the kernel's entry writes its offset. + // The loader and the kernel both speak on the PL011. + let mut qemu = QemuInstance::boot_with_options( + test_config, + &[], + &[], + BootOptions { profile, ready_marker: "control registers: SCTLR_EL1=", ..Default::default() }, + ); + let rest = + qemu.drain_until(Duration::from_secs(180), |l| l.contains(POWER_ON) || l.contains(COUNTER_BACKWARDS)); + boot_from_power_on(&format!("{}\n{rest}", qemu.boot_log()), profile.arch()) + } "virt_timer_preempts" => { // Spelled in `userland/toybox/src/preempt.rs`. virt_job(profile, "preempt", "preempt: the counting thread was preempted twice") @@ -12113,7 +12128,7 @@ fn run_machine_test( "boot_from_power_on" => { let qemu = QemuInstance::boot(test_config, c_bins, rust_bins); // The loader speaks on the firmware's serial, the kernel on the console. - boot_from_power_on(&format!("{}{}", qemu.uart_log(), qemu.boot_log())) + boot_from_power_on(&format!("{}{}", qemu.uart_log(), qemu.boot_log()), toyos_build::arch::Arch::X86_64) } "root_withheld_refused" => { let qemu = QemuInstance::boot_with_options( @@ -17440,17 +17455,28 @@ fn root_from_memory(log: &str) -> Result<(), String> { Ok(()) } -const LOADER_TSC: &str = "Loader TSC: "; +/// The loader's line, followed by its counter at its entry and at its handoff. +const LOADER_COUNTER: &str = "Loader counter: "; /// The kernel's line, followed by its four spans in milliseconds. const POWER_ON: &str = "boot: power-on to loader "; +/// The kernel's line in place of [`POWER_ON`] when the loader's counts and its +/// own are out of order. +const COUNTER_BACKWARDS: &str = "boot: the counter went backwards"; /// The kernel's `TSC:` record, followed by the period it calibrated. const TSC_PERIOD: &str = "MHz (period="; +/// The kernel's `clock:` record on AArch64, followed by the rate `CNTFRQ_EL0` +/// states. +const GENERIC_TIMER_HZ: &str = "clock: the generic timer counts at "; /// **The boot from power-on is the loader's raw counts at the kernel's rate.** -/// The kernel's first two spans are the loader's counts converted at the `TSC:` -/// record's period, the ROOT read sits inside the loader's span, and +/// The kernel's first two spans are the loader's counts converted at the period +/// its clock record gives, the ROOT read sits inside the loader's span, and /// `Boot: complete`'s own count inside the kernel's. -fn boot_from_power_on(log: &str) -> Result<(), String> { +fn boot_from_power_on(log: &str, arch: toyos_build::arch::Arch) -> Result<(), String> { + use toyos_build::arch::Arch; + if let Some(line) = log.lines().find(|l| l.contains(COUNTER_BACKWARDS)) { + return Err(line.to_string()); + } let after = |head: &str| -> Result, String> { let at = log.find(head).ok_or_else(|| format!("no {head:?} line in the boot log"))?; let line = log[at + head.len()..].lines().next().unwrap_or(""); @@ -17460,13 +17486,18 @@ fn boot_from_power_on(log: &str) -> Result<(), String> { .map(|word| word.parse().expect("a run of digits")) .collect()) }; - let (loader, spans, rate) = (after(LOADER_TSC)?, after(POWER_ON)?, after(TSC_PERIOD)?); - let (&[entry, handoff, ..], &[to_loader, in_loader, root_read, to_complete], &[period_fs, ..]) = - (&loader[..], &spans[..], &rate[..]) + // AArch64's record is a rate, which the kernel divides into a second as this does. + let (rate_head, period_of): (&str, fn(u128) -> Option) = match arch { + Arch::X86_64 => (TSC_PERIOD, Some), + Arch::Aarch64 => (GENERIC_TIMER_HZ, |hz| 1_000_000_000_000_000u128.checked_div(hz)), + }; + let (loader, spans, rate) = (after(LOADER_COUNTER)?, after(POWER_ON)?, after(rate_head)?); + let (&[entry, handoff, ..], &[to_loader, in_loader, root_read, to_complete], Some(period_fs)) = + (&loader[..], &spans[..], rate.first().copied().and_then(period_of)) else { return Err(format!( - "the lines do not carry their numbers: {loader:?} after {LOADER_TSC:?}, {spans:?} after \ - {POWER_ON:?}, {rate:?} after {TSC_PERIOD:?}" + "the lines do not carry their numbers: {loader:?} after {LOADER_COUNTER:?}, {spans:?} \ + after {POWER_ON:?}, {rate:?} after {rate_head:?}" )); }; let ms = |ticks: u128| ticks * period_fs / 1_000_000_000_000; @@ -17488,10 +17519,16 @@ fn boot_from_power_on(log: &str) -> Result<(), String> { power-on line puts at {to_complete} ms" )); } + let origin = match arch { + Arch::X86_64 => format!( + "; IA32_TSC_ADJUST {}", + log.split("IA32_TSC_ADJUST ").nth(1).and_then(|rest| rest.lines().next()).unwrap_or("unsaid") + ), + Arch::Aarch64 => String::new(), + }; eprintln!( " [boot] power-on to loader {to_loader} ms, loader {in_loader} ms (ROOT read {root_read} \ - ms), kernel {to_complete} ms; IA32_TSC_ADJUST {}", - log.split("IA32_TSC_ADJUST ").nth(1).and_then(|rest| rest.lines().next()).unwrap_or("unsaid") + ms), kernel {to_complete} ms{origin}" ); Ok(()) } diff --git a/toyos-abi/src/boot.rs b/toyos-abi/src/boot.rs index 07703906afb..33c34e9f158 100644 --- a/toyos-abi/src/boot.rs +++ b/toyos-abi/src/boot.rs @@ -101,13 +101,13 @@ pub struct KernelArgs { /// GPT entry like [`Self::boot_partition_guid`]; zero with no image. The /// kernel holds that partition so no claim writes the slot it is running. pub root_partition_guid: [u8; 16], - /// The time-stamp counter at the loader's entry and at its handoff, and the - /// cycles its read of ROOT took (zero with no image). The TSC counts from - /// reset, so the first is firmware's time since power-on unless firmware - /// wrote the counter; the kernel converts all three at its calibrated rate. - pub loader_entry_tsc: u64, - pub loader_handoff_tsc: u64, - pub root_read_tsc: u64, + /// The CPU's counter, the one the kernel's clock reads, at the loader's + /// entry and at its handoff, and the ticks its read of ROOT took (zero with + /// no image). The first is firmware's time since the counter started; the + /// kernel converts all three at its clock's rate. + pub loader_entry_counter: u64, + pub loader_handoff_counter: u64, + pub root_read_ticks: u64, } /// [`KernelArgs::layout`] for the struct this file declares: the struct's own @@ -222,9 +222,9 @@ const _: () = { assert!(offset_of!(KernelArgs, root_image_addr) == 1216); assert!(offset_of!(KernelArgs, root_image_len) == 1224); assert!(offset_of!(KernelArgs, root_partition_guid) == 1232); - assert!(offset_of!(KernelArgs, loader_entry_tsc) == 1248); - assert!(offset_of!(KernelArgs, loader_handoff_tsc) == 1256); - assert!(offset_of!(KernelArgs, root_read_tsc) == 1264); + assert!(offset_of!(KernelArgs, loader_entry_counter) == 1248); + assert!(offset_of!(KernelArgs, loader_handoff_counter) == 1256); + assert!(offset_of!(KernelArgs, root_read_ticks) == 1264); assert!(size_of::() == 1272); assert!(LAYOUT as i32 > 1440 || (LAYOUT as i32) < -1440); assert!(align_of::() == 8); @@ -317,9 +317,9 @@ mod tests { root_image_addr: 0, root_image_len: 0, root_partition_guid: [0; 16], - loader_entry_tsc: 0, - loader_handoff_tsc: 0, - root_read_tsc: 0, + loader_entry_counter: 0, + loader_handoff_counter: 0, + root_read_ticks: 0, }; #[test] From 97bb62406ddbbeeb5fd60ba561243487c03efb80 Mon Sep 17 00:00:00 2001 From: japabu Date: Thu, 1 Oct 2026 04:29:08 +0200 Subject: [PATCH 2/4] AArch64 loader: at EL2 the counter it hands is the physical count the kernel's clock reads KernelArgs' counter readings are converted by the kernel against its own cpu::counter, CNTVCT_EL0. Entered at EL2, the kernel's entry writes CNTVOFF_EL2 zero before its clock starts, so from then on its virtual count is the physical count. The loader read CNTVCT_EL0 before that write, under whatever offset firmware left; the Arm ARM resets CNTVOFF_EL2 to an UNKNOWN value. The loader's readings and the kernel's were in one frame only where firmware left the offset zero. At EL2 the loader now reads CNTPCT_EL0, which EL2 may always read and which no offset moves. At EL1 the offset is the hypervisor's, the kernel never writes it, and CNTVCT_EL0 stays the right count. cpu_as_entered and counter share current_el. Shown by virt_boot_from_power_on under a mutation that puts an hour's offset in CNTVOFF_EL2 around each loader reading and takes it back after, interrupts masked so firmware's timer never sees it: green with this change, and red ("the counter went backwards") with the EL2 arm reading CNTVCT_EL0 again. Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_016t9wjdQkB8SH7bmfUoiy6L --- bootloader/src/arch/aarch64.rs | 30 ++++++++++++++++++++++-------- tests/toyos.rs | 6 +++--- 2 files changed, 25 insertions(+), 11 deletions(-) diff --git a/bootloader/src/arch/aarch64.rs b/bootloader/src/arch/aarch64.rs index a85bd2560b2..6a30fa65644 100644 --- a/bootloader/src/arch/aarch64.rs +++ b/bootloader/src/arch/aarch64.rs @@ -15,12 +15,29 @@ pub fn typing(write_back: &[(u64, u64)]) -> Typing<'_> { Typing::ByMap(write_back) } -/// The generic timer's virtual count, `CNTVCT_EL0`. +/// The exception level the loader runs at, from `CurrentEL`. +fn current_el() -> u64 { + let current: u64; + // SAFETY: reads `CurrentEL`, which EL1 and above may read. + unsafe { core::arch::asm!("mrs {}, currentel", out(reg) current, options(nomem, nostack, preserves_flags)) }; + (current >> 2) & 0b11 +} + +/// The count the kernel's clock reads, its virtual count. At EL2 that is the +/// physical count, `CNTPCT_EL0`, because the kernel's entry writes +/// `CNTVOFF_EL2` zero, which resets UNKNOWN; at EL1 the offset is the +/// hypervisor's for good and `CNTVCT_EL0` is read. pub fn counter() -> u64 { let count: u64; - // SAFETY: reads a counter EL1 and EL2 may always read; the `ISB` keeps the - // read in program order. - unsafe { core::arch::asm!("isb", "mrs {}, cntvct_el0", out(reg) count, options(nomem, nostack, preserves_flags)) }; + if current_el() == 2 { + // SAFETY: reads a counter EL2 may always read; the `ISB` keeps the + // read in program order. + unsafe { core::arch::asm!("isb", "mrs {}, cntpct_el0", out(reg) count, options(nomem, nostack, preserves_flags)) }; + } else { + // SAFETY: reads a counter EL1 may always read; the `ISB` keeps the + // read in program order. + unsafe { core::arch::asm!("isb", "mrs {}, cntvct_el0", out(reg) count, options(nomem, nostack, preserves_flags)) }; + } count } @@ -31,10 +48,7 @@ pub fn counter() -> u64 { /// the console still prints; the entry's read-back of `HCR_EL2` stays as the /// last line of defence. pub fn cpu_as_entered() -> Result, alloc::string::String> { - let current: u64; - // SAFETY: reads `CurrentEL`, which EL1 and above may read. - unsafe { core::arch::asm!("mrs {}, currentel", out(reg) current, options(nomem, nostack, preserves_flags)) }; - let el = (current >> 2) & 0b11; + let el = current_el(); if el != 2 { return Ok(Some(alloc::format!("CPU: entered at EL{el}"))); } diff --git a/tests/toyos.rs b/tests/toyos.rs index 663b42d294a..9d75c3a3b33 100644 --- a/tests/toyos.rs +++ b/tests/toyos.rs @@ -5221,9 +5221,9 @@ fn run_screen_test( Ok(()) } "virt_boot_from_power_on" => { - // `boot_from_power_on` where the loader's counter is the generic - // timer's, read at EL2 before the kernel's entry writes its offset. - // The loader and the kernel both speak on the PL011. + // `boot_from_power_on` on the generic timer, entered at EL2: the + // loader reads the physical count, the kernel the virtual one once + // its entry writes the offset zero. Both speak on the PL011. let mut qemu = QemuInstance::boot_with_options( test_config, &[], From 91b4b0823c40e9143fcef13a1ecfc856c104636d Mon Sep 17 00:00:00 2001 From: japabu Date: Fri, 2 Oct 2026 21:37:22 +0200 Subject: [PATCH 3/4] AArch64 track: the loader's EL2 counter read is owed its red beside the entry's three writes Measured at 71922876e with bootloader/src/arch/aarch64.rs's counter put back to 38d28863e's, one read of CNTVCT_EL0 at either level: `cargo test --test toyos-build -- virt_boot_from_power_on --nocapture` exits 0. QEMU's firmware hands the loader EL2 with CNTVOFF_EL2 zero, so the two counts read the same there and the row cannot tell which the loader took. 97bb62406's message says the arm is "shown by virt_boot_from_power_on under a mutation"; that pair was not run until 71922876e, where it reads: an hour in CNTVOFF_EL2 around each loader reading exits 0 as the loader stands, and exits 1 on "boot: the counter went backwards" with the EL2 arm reading CNTVCT_EL0. A mutation is no standing test, so stage 4's owed list takes the arm, with the exit the entry's writes already have there. Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_013UDZQ6fSKw14e4w2TKTRfm --- issues/kernel/toyos-runs-on-arm64.md | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/issues/kernel/toyos-runs-on-arm64.md b/issues/kernel/toyos-runs-on-arm64.md index 37f44bc331a..dad2751732f 100644 --- a/issues/kernel/toyos-runs-on-arm64.md +++ b/issues/kernel/toyos-runs-on-arm64.md @@ -267,7 +267,10 @@ Each stage names its exit; "measured" means a number from a run. entry's replacement, and the TLB flush before a reclaimed ASID is issued again, which QEMU's TCG, the only oracle this stage has, cannot fail on: the first HVF run, once stage 6 gives HVF its RNDR, is their exit; and the - three deletions shown red. They are shown red on a machine whose + three deletions shown red, and with them the loader's read of `CNTPCT_EL0` + at EL2 (`bootloader/src/arch/aarch64.rs`'s `counter`): with that arm + reading `CNTVCT_EL0`, `virt_boot_from_power_on` stays green, because + QEMU's firmware leaves `CNTVOFF_EL2` zero. They are shown red on a machine whose firmware leaves the registers otherwise, or by a loader that writes the opposite values before the handoff. The ITS moves to stage 6: a claimed function is its only consumer the small-kernel track leaves, and it needs that From 5bf33470c970eabbcf080d95d9c5a669cc6109fb Mon Sep 17 00:00:00 2001 From: japabu Date: Fri, 2 Oct 2026 22:16:25 +0200 Subject: [PATCH 4/4] virt_boot_from_power_on goes: it cannot fail on the EL2 count's frame, and the handoff's tier is metal's Review of 91b4b0823 (#657, issuecomment-5960716527). The row was added to judge 97bb62406, the loader reading `CNTPCT_EL0` at EL2. With that arm reverted and nothing else it stays green (f0, exit 0): on QEMU's firmware the two counts are one. What it did fail on is the architecture-neutral handoff in `kernel/src/main.rs` and `bootloader/src/main.rs`, whose tier `issues/build/the-guest-suite-runs-only-what-no-cheaper-tier-reaches.md` already names: the metal row `boot_from_power_on`, the judge 520c0d129 cut from QEMU. So the row, its four constants, the judge and the arm go, and `tests/toyos.rs` is `main`'s again. The track's sentence that filed the loader's EL2 read as owed its red goes with it. The exit `main` wrote for the entry's three writes has two arms, and the second, "a loader that writes the opposite values before the handoff", is the negative control this pull request carries: with an hour staged in `CNTVOFF_EL2` around each loader reading, the loader as it stands is green and the loader reading `CNTVCT_EL0` is red, the judge carried in the patch. That red is measured at this commit and recorded in the pull request's body; nothing is owed. Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_013UDZQ6fSKw14e4w2TKTRfm --- issues/kernel/toyos-runs-on-arm64.md | 5 +- tests/toyos.rs | 80 ---------------------------- 2 files changed, 1 insertion(+), 84 deletions(-) diff --git a/issues/kernel/toyos-runs-on-arm64.md b/issues/kernel/toyos-runs-on-arm64.md index dad2751732f..37f44bc331a 100644 --- a/issues/kernel/toyos-runs-on-arm64.md +++ b/issues/kernel/toyos-runs-on-arm64.md @@ -267,10 +267,7 @@ Each stage names its exit; "measured" means a number from a run. entry's replacement, and the TLB flush before a reclaimed ASID is issued again, which QEMU's TCG, the only oracle this stage has, cannot fail on: the first HVF run, once stage 6 gives HVF its RNDR, is their exit; and the - three deletions shown red, and with them the loader's read of `CNTPCT_EL0` - at EL2 (`bootloader/src/arch/aarch64.rs`'s `counter`): with that arm - reading `CNTVCT_EL0`, `virt_boot_from_power_on` stays green, because - QEMU's firmware leaves `CNTVOFF_EL2` zero. They are shown red on a machine whose + three deletions shown red. They are shown red on a machine whose firmware leaves the registers otherwise, or by a loader that writes the opposite values before the handoff. The ITS moves to stage 6: a claimed function is its only consumer the small-kernel track leaves, and it needs that diff --git a/tests/toyos.rs b/tests/toyos.rs index fc1193b09c6..7fb33c083ca 100644 --- a/tests/toyos.rs +++ b/tests/toyos.rs @@ -146,7 +146,6 @@ const SCREEN_TESTS: &[(&str, qemu::Profile)] = &[ ("virt_early_fault", qemu::Profile::Virt), ("virt_el2_drop", qemu::Profile::VirtEl2NoVhe), ("virt_user_mode", qemu::Profile::VirtEl2), - ("virt_boot_from_power_on", qemu::Profile::VirtEl2), ("virt_timer_preempts", qemu::Profile::VirtEl2), ("virt_irq_storm", qemu::Profile::VirtEl2), ("virt_timer_floor", qemu::Profile::VirtEl2), @@ -1377,71 +1376,6 @@ fn judge_virt_job(qemu: &mut QemuInstance, job: &str, said: &str) -> Result Result<(), String> { - if let Some(line) = log.lines().find(|l| l.contains(COUNTER_BACKWARDS)) { - return Err(format!("{line}\nserial:\n{log}")); - } - let after = |head: &str| -> Result, String> { - let at = log.find(head).ok_or_else(|| format!("no {head:?} line on the PL011\nserial:\n{log}"))?; - let line = log[at + head.len()..].lines().next().unwrap_or(""); - Ok(line - .split(|c: char| !c.is_ascii_digit()) - .filter(|word| !word.is_empty()) - .map(|word| word.parse().expect("a run of digits")) - .collect()) - }; - let (loader, spans, rate) = (after(LOADER_COUNTER)?, after(POWER_ON)?, after(GENERIC_TIMER_HZ)?); - let (&[entry, handoff, ..], &[to_loader, in_loader, root_read, to_complete], Some(period_fs)) = ( - &loader[..], - &spans[..], - rate.first().and_then(|&hz| 1_000_000_000_000_000u128.checked_div(hz)), - ) else { - return Err(format!( - "the lines do not carry their numbers: {loader:?} after {LOADER_COUNTER:?}, {spans:?} \ - after {POWER_ON:?}, {rate:?} after {GENERIC_TIMER_HZ:?}" - )); - }; - let ms = |ticks: u128| ticks * period_fs / 1_000_000_000_000; - if (to_loader, in_loader) != (ms(entry), ms(handoff - entry)) { - return Err(format!( - "the kernel says {to_loader} ms to the loader and {in_loader} ms in it; the loader's \ - counts {entry} and {handoff} at {period_fs} fs a tick are {} and {}", - ms(entry), - ms(handoff - entry) - )); - } - if root_read > in_loader { - return Err(format!("the ROOT read took {root_read} ms of a loader that took {in_loader}")); - } - let complete = after("Boot: complete (")?; - if complete.first().is_none_or(|&own| own > to_complete) { - return Err(format!( - "`Boot: complete` counts {complete:?} ms from its own start, inside a kernel span the \ - power-on line puts at {to_complete} ms" - )); - } - eprintln!( - " [boot] power-on to loader {to_loader} ms, loader {in_loader} ms (ROOT read {root_read} \ - ms), kernel {to_complete} ms" - ); - Ok(()) -} - /// What `unmap_touch` says once every read of a page just unmapped, /// on the unmapping thread and on another, ended its process. const UNMAP_TOUCH_SAID: &str = @@ -2015,20 +1949,6 @@ fn run_screen_test(name: &str, profile: qemu::Profile, test_config: &Path) -> Re } Ok(()) } - "virt_boot_from_power_on" => { - // Entered at EL2: the loader reads the physical count, the kernel - // the virtual one once its entry writes the offset zero. Both speak - // on the PL011. - let mut qemu = QemuInstance::boot_with_options( - test_config, - &[], - &[], - BootOptions { profile, ready_marker: "control registers: SCTLR_EL1=", ..Default::default() }, - ); - let rest = - qemu.drain_until(Duration::from_secs(180), |l| l.contains(POWER_ON) || l.contains(COUNTER_BACKWARDS)); - boot_from_power_on(&format!("{}\n{rest}", qemu.boot_log())) - } "virt_timer_preempts" => virt_job(profile, "preempt", "preempt: the counting thread was preempted twice"), "virt_fp_isolation" => virt_job(profile, "fp_isolation", "fp_isolation: v0-v31, FPCR and FPSR survived"), "virt_first_entry" => virt_job(profile, "first_entry", "first_entry: x1-x30 were zero"),