Reference

Test output format

What the kernel test harness prints on the serial console, and the JSON events and exit codes the host test runner produces from it.

When SlopOS boots with tests=on, the kernel test harness prints its results on the serial console in KTAP, the Linux kernel's test output format. The host runner (tools/run_tests/, built to builddir/run_tests and run by just test) reads that stream, shows progress, and can write the results as JSON lines. This page lists both formats and the runner's exit codes. The emitter is the ktesting crate; the parser is tools/run_tests/parser.go and the JSON writer tools/run_tests/jsonl.go. The options that control the harness (tests.run, tests.verbosity and the rest) are listed in Boot options.

Phases

PhaseTests registered withRun by
1, kernelstest!The kernel during boot
2, userlandutest!, one userland program per testinit, which asks the kernel to run them

Each phase prints its own header. The runner names phases by order: the first TAP version 14 header is the kernel phase, the second the userland phase.

Line prefix

Every harness line starts with KTAP and a tab. Ordinary kernel log lines are interleaved with them and the parser ignores those. Diagnostic and subtest lines add two spaces after the tab.

KTAP	TAP version 14
KTAP	1..N

N is the number of tests in the phase after tests.run and tests.skip are applied. A filter that matches nothing gives 1..0.

Result lines

KTAP	ok 17 - slopos_mm::tests::heap::test_heap_kzalloc_zeroed # time_ms=3
KTAP	ok 18 - slopos_core::tests::sched::test_slow_path # time_ms=812 OVER_TIME
KTAP	ok 19 - slopos_net::tests::tcp_live::test_loopback_handshake # SKIP test returned Skipped
KTAP	not ok 42 - slopos_core::tests::sched::test_priority_inversion # time_ms=11

The name is module::test. The text after # holds:

TokenMeaning
time_ms=NHow long the test took
NO_TIME_BASEIn place of time_ms when no clock was available
OVER_TIMEPassed, but slower than tests.warn_ms
EXPECTED_PANICThe test was registered as expecting a panic, and panicked
SKIP <reason>Skipped; KTAP writes a skip as ok

With tests.verbosity=quiet the harness prints only failing results.

Diagnostic block

A failing test is followed by a block in YAML style:

KTAP	  ---
KTAP	  outcome: Fail
KTAP	  file: core/src/sched/tests.rs:1832
KTAP	  log: |
KTAP	   captured klog line
KTAP	   --- cpu2 ---
KTAP	   klog line captured on another CPU
KTAP	  ...
KeyMeaning
outcomeFail or Panic
fileSource location of the failure
logKernel log captured while the test ran: the harness CPU first, then a --- cpuN --- section for each other CPU that logged

When the capture was cut short, the log contains [head trimmed: N bytes] (the test logged more than the per-test limit) or [cpuN tail trimmed: N bytes lost to ring overflow] (a CPU's log buffer wrapped). With tests.verbosity=verbose a passing test may print a block with only log.

Subtests

A utest! program reports its individual cases with the test_report system call. The kernel prints each case as an indented line, before the parent's result line:

KTAP	  ok 1 - alloc_basic
KTAP	  ok 2 - alloc_large # 4 MiB in 3 ms
KTAP	  not ok 3 - alloc_zero # zero-size returned null
KTAP	  ok 4 - alloc_huge # SKIP
KTAP	ok 5 - slopos_core::utests::utest_heap_allocator # time_ms=234
  • The parser collects indented lines and attaches them to the next top-level result.
  • On a passing case, text after # is a note; only SKIP changes the outcome. On a failing case it is the failure message.
  • Notes and messages are cut to their first line.
  • Subtest lines go straight to the console rather than through the per-test log capture, so a long test that overflows the capture cannot lose them.
KTAP	# elapsed_ms=14238 pass=2391 fail=1 skip=0 over_time=14
  • Each phase ends with a footer holding its time and counters.
  • If a test whose name starts with bootstrap_ fails, the harness prints KTAP Bail out! <reason> and runs no more tests in that phase.
  • A kernel panic prints a === KERNEL ABORT === banner, which the runner records as a kernel abort.
  • With tests.shutdown=on, the kernel then writes 0 (all passed) or 1 (something failed) to QEMU's isa-debug-exit device. QEMU exits with (value << 1) | 1, so the runner does not rely on that status alone: it also requires at least one phase header.

Host runner

RecipeRunner flagEffect
just test FILTER--filter GLOBRepeatable; joined with commas into tests.run=
--skip GLOBRepeatable; joined into tests.skip=
--warn-ms Ntests.warn_ms=N; default 500
just test-rerun-failed--rerun-failedRuns the failures recorded in builddir/last-fail.list
just test-verbose--verbosetests.verbosity=verbose; shows the captured log of every test
just test-quiet--quiettests.verbosity=quiet; shows only failures and the summary
just test-raw--rawPrints QEMU's serial output unchanged
just test-json PATH--json PATHAppends one JSON event per line to PATH
--timeout-secs NStops the whole run after N seconds; default 900, 0 disables
--silence-secs NStops the run if QEMU prints nothing for N seconds; default 120, 0 disables
--dry-runPrints the command line it would use and exits

--verbose, --quiet and --raw exclude each other. --raw still parses the stream to decide the exit code. The runner starts from the command line tests=on tests.shutdown=on tests.verbosity=summary boot.debug=on roulette=skip mount=LABEL=slopos-media:/media and adds the options its flags select.

Exit codes

CodeMeaning
0Tests ran and all passed
1A test failed, a phase bailed out, the run timed out, the output was cut short, or the kernel aborted
2No trustworthy answer: no phase header appeared, an unfiltered run planned zero tests, or QEMU's wrapper exited with an unexpected status
64Bad command-line arguments
130Interrupted with Ctrl-C

JSON lines

--json PATH writes one JSON object per line. Every object has a t field naming the event. Every field is always present; a missing value is null.

tFields
phase_startidx, name
planphase_idx, n
testphase, phase_idx, idx, name, outcome, time_ms, over_time, expected_panic, skip_reason, fail_file, fail_outcome_kind, log, pre_fail_klog_tail, subtests
phase_endidx, name, elapsed_ms, pass, fail, skip, over_time
bailphase_idx, reason
kernel_abortreason
run_endwall_ms, exit, qemu_status, user_aborted, timed_out, silence_hit, truncated, kernel_abort, kernel_abort_reason, phases
  • outcome is one of pass, fail, skip, bail, not_run, timeout.
  • Each entry in subtests has idx, name, outcome and msg.
  • fail_outcome_kind is the diagnostic block's outcome (Fail or Panic).
  • pre_fail_klog_tail holds recent console lines that were not KTAP, for a failure that carried no captured log.
  • run_end is always the last event. Each entry in its phases array has idx, name, plan_n, elapsed_ms, pass, fail, skip, over_time and bail (the bail-out reason, or null).
{"expected_panic":false,"fail_file":null,"fail_outcome_kind":null,"idx":17,"log":null,"name":"slopos_mm::tests::heap::test_heap_kzalloc_zeroed","outcome":"pass","over_time":false,"phase":"kernel","phase_idx":1,"pre_fail_klog_tail":null,"skip_reason":null,"subtests":[],"t":"test","time_ms":3}

See also

On this page