fix(guest): acpi_init was never 18000 us, it was 18 jiffies

[aledbf]

Two things this profiler reported as measurements were not measurements.

1. The initcall durations were quantised to 1 ms

initcall_debug prints what ktime_get() gives it, and until the TSC clocksource is registered that is served by the jiffies clocksource — resolution 1/HZ, so 1 ms here (CONFIG_HZ=1000). Every initcall in the core/postcore/arch/subsys levels runs before that registration.

Across 42 boots this profiler reported acpi_init as 2000, 6000, 7000, 17000, 18000, 19000 or 20000 µs and never once anything in between, while device-level initcalls in the same boots came back as 6447, 7003, 2756. The number looked precise to the microsecond and carried 1 ms of quantisation — enough to hide any change smaller than itself. Several A/B comparisons were run against that column before it was noticed.

The initcall_start/initcall_finish tracepoints are already enabled at boot for the level breakdown, and ftrace timestamps come from local_clock(), which is TSC-backed from very early boot. Durations now come from there, with the initcall_debug values kept as the fallback when the tracepoints are absent. The header says which was used: source=tracepoints refined=662/662.

Same three boots, before and after:

initcall	before	after
acpi_init	18000 / 18000 / 19000	20252 / 20188 / 18437
pci_subsys_init	0 / 1000 / 0	74 / 105 / 74

The second row is the point: sub-millisecond initcalls were reported as zero.

2. The host was not always idle

These tests time a boot to the millisecond on a machine that is also this repository's self-hosted CI runner, where a task build:kernel from an unrelated push takes all 20 cores for minutes. One such overlap showed up as a pid1-entry of 78 ms against a median of 51 — the only outlier in twelve runs, and unexplained at the time.

requireQuietHost samples /proc/stat and waits for ambient CPU use to fall below 25%, skipping the test if it has not settled in 30 s. It gates the four measurement tests (TestBootLatency, TestVminitdReady, TestKernelBootProfileComplete, TestUserspaceBootProfile).

The gate is on measured CPU rather than on the runner's process, for two reasons: it catches a manual build or a concurrent benchmark too, and it does not fire merely because these tests are themselves running inside a CI job, where a Runner.Worker always exists and is idle. The measured value is logged either way, so a number just under the threshold is visible next to the timing it produced.

Verified in both directions:

idle:        HOST_QUIET host 0.0% busy (threshold 25%)   --- PASS
20 hogs:     HOST_QUIET host 100.0% busy after 30s ...   --- SKIP

Checks

• Full integration suite passes with the rebuilt initrd.
• task lint 0 issues, go test -race on the touched package passes.

🤖 Generated with Claude Code

[codecov]

Codecov Report

❌ Patch coverage is 0% with 46 lines in your changes missing coverage. Please review.

Files with missing lines	Patch %	Lines
internal/guest/vminit/system/kmsg.go	0.00%	46 Missing ⚠️

📢 Thoughts on this report? Let us know!