diff --git a/run-vmtest/README.md b/run-vmtest/README.md index 1bebe63..2617526 100644 --- a/run-vmtest/README.md +++ b/run-vmtest/README.md @@ -47,24 +47,24 @@ hung tasks and lockups. A hit adds a `kernel_splats` row to `exitstatus`, which turns the run red like any other failing test group. Anything fatal panics the VM instead, and fails the job on its own. -The check runs for the default suite or when the requested runners include -`test_progs`. Veristat-only runs skip it. +Leave both splat list files absent to disable detection. The action carries no patterns. What a splat is, and what is benign, is policy that changes per arch and per kernel, so it lives with the configs. Two files of extended regexes, one per line, `#` comments and blank lines ignored, named by `run-vmtest.env` next to the allow and denylists: -* `SPLAT_DENYLIST_FILE` - a matching dmesg line is a splat. **Required.** +* `SPLAT_DENYLIST_FILE` - a matching dmesg line is a splat. * `SPLAT_ALLOWLIST_FILE` - a matching splat line is ignored. Optional. -The denylist is required on purpose: with no patterns there is no check, so a -missing or empty file fails the run rather than reporting a clean log. +If either file exists, the denylist must exist and contain at least one +pattern. See `ci/vmtest/configs/SPLAT_DENYLIST` for the set BPF CI uses. -`dmesg.txt` is written to the output dir and uploaded as the `kernel-log-*` -artifact, so the full log is always one click away. +On failure, matching kernel log context is printed in the job log. `dmesg.txt` +is also written to the output dir and uploaded as the `kernel-log-*` artifact +for the full log. ## run-vmtest.env diff --git a/run-vmtest/check-kernel-splats.sh b/run-vmtest/check-kernel-splats.sh index 28ee528..e7db4f1 100755 --- a/run-vmtest/check-kernel-splats.sh +++ b/run-vmtest/check-kernel-splats.sh @@ -7,15 +7,16 @@ # config repo rather than here: # # SPLAT_DENYLIST_FILE extended regexes; a matching dmesg line is a splat. -# Required: with no patterns there is no check, so a -# missing file fails the run instead of passing it. +# Required if either splat list file exists. # SPLAT_ALLOWLIST_FILE extended regexes; a matching splat line is ignored. # Optional: no file means no exceptions. # # `#` comments and blank lines are ignored in both. See run-vmtest.env in the # repo that owns $VMTEST_CONFIGS. # -# The whole log is written to dmesg.txt, which the workflow uploads. +# The whole log is written to dmesg.txt, which the workflow uploads. A short +# excerpt around unallowlisted hits is written next to the status file so the +# host can print it after closing the folded VM log. # # $1 - log file to scan instead of running dmesg (used by the unit tests) @@ -27,11 +28,20 @@ STATUS_FILE=${STATUS_FILE:-/mnt/vmtest/exitstatus} OUTPUT_DIR=${OUTPUT_DIR:-/mnt/vmtest} SPLAT_DENYLIST_FILE=${SPLAT_DENYLIST_FILE:-} SPLAT_ALLOWLIST_FILE=${SPLAT_ALLOWLIST_FILE:-} +SPLAT_LOG_FILE=${SPLAT_LOG_FILE:-"$(dirname "${STATUS_FILE}")/kernel_splats.log"} + +rm -f "${SPLAT_LOG_FILE}" + +if [ ! -e "${SPLAT_DENYLIST_FILE}" ] && [ ! -e "${SPLAT_ALLOWLIST_FILE}" ]; then + echo "Skipping kernel splat check: no allowlist or denylist files found" + exit 0 +fi # Fail the row and stop. Also used when the scan cannot run: a check that is # not working must not look like a clean log. fail_check() { echo "$1" + printf '%s\n' "$1" > "${SPLAT_LOG_FILE}" echo "kernel_splats:1" >> "${STATUS_FILE}" foldable end kernel_splats exit 0 @@ -78,5 +88,8 @@ if [ -z "${hits}" ]; then fi echo "kernel_splats:1" >> "${STATUS_FILE}" -grep -nC 30 -E -f <(printf '%s\n' "${deny}") "${log}" || true -echo "::error title=kernel_splats::kernel splat detected, see the dmesg.txt artifact" +first_hit=${hits%%$'\n'*} +{ + printf 'kernel splat detected: %s\n' "${first_hit}" + grep -nC 30 -F -f <(printf '%s\n' "${hits}") "${log}" || true +} > "${SPLAT_LOG_FILE}" diff --git a/run-vmtest/prepare-bpf-selftests.sh b/run-vmtest/prepare-bpf-selftests.sh index 4470223..fb9b846 100755 --- a/run-vmtest/prepare-bpf-selftests.sh +++ b/run-vmtest/prepare-bpf-selftests.sh @@ -1,6 +1,6 @@ #!/bin/bash -set -xeuo pipefail +set -euo pipefail if [[ -z "${SELFTESTS_BPF_ALLOWLIST_FILES:-}" && -z "${SELFTESTS_BPF_DENYLIST_FILES:-}" ]]; then exit 0 diff --git a/run-vmtest/run-bpf-selftests.sh b/run-vmtest/run-bpf-selftests.sh index da4af1f..151e62c 100755 --- a/run-vmtest/run-bpf-selftests.sh +++ b/run-vmtest/run-bpf-selftests.sh @@ -12,7 +12,7 @@ # Runners passed as arguments are executed. In case of no arguments, # all test runners are executed. -set -xeuo pipefail +set -euo pipefail SCRIPT_DIR="$(cd "$(dirname "$0")" && pwd)" source "${SCRIPT_DIR}/helpers.sh" @@ -178,8 +178,4 @@ else done fi -if [ ${#TEST_NAMES[@]} -eq 0 ] || [[ "${TEST_NAMES[*]}" == *test_progs* ]]; then - "${SCRIPT_DIR}/check-kernel-splats.sh" -else - echo "Skipping kernel splat check: test_progs not requested" -fi +"${SCRIPT_DIR}/check-kernel-splats.sh" diff --git a/run-vmtest/run.sh b/run-vmtest/run.sh index 545590e..3fc30b8 100755 --- a/run-vmtest/run.sh +++ b/run-vmtest/run.sh @@ -1,6 +1,6 @@ #!/bin/bash -set -xeuo pipefail +set -euo pipefail trap 'exit 2' ERR source "${GITHUB_ACTION_PATH}/../helpers.sh" @@ -117,6 +117,17 @@ rm -f $VMTEST_TOML foldable end vmtest +if grep -q '^kernel_splats:1$' exitstatus; then + splat_error="kernel splat check failed" + if [[ -s kernel_splats.log ]]; then + cat kernel_splats.log + splat_error=$(head -n 1 kernel_splats.log) + fi + splat_error=${splat_error//'%'/'%25'} + splat_error=${splat_error//$'\r'/'%0D'} + printf '::error title=kernel_splats::%s\n' "${splat_error}" +fi + foldable start collect_status "Collecting exit status" exitfile="$(cat exitstatus 2>/dev/null)" diff --git a/run-vmtest/tests/check_kernel_splats/cases/kasan/expected-output.txt b/run-vmtest/tests/check_kernel_splats/cases/kasan/expected-output.txt index 0769d2f..d1c6439 100644 --- a/run-vmtest/tests/check_kernel_splats/cases/kasan/expected-output.txt +++ b/run-vmtest/tests/check_kernel_splats/cases/kasan/expected-output.txt @@ -2,17 +2,3 @@ Splat denylist: $VMTEST_CONFIGS/SPLAT_DENYLIST Splat allowlist: $VMTEST_CONFIGS/SPLAT_ALLOWLIST ::endgroup:: -1-[ 0.000000] Linux version 6.5.0 -2-[ 20.000000] ================================================================== -3:[ 20.000001] BUG: KASAN: slab-use-after-free in foo+0x42/0x100 -4-[ 20.000002] Read of size 8 at addr ffff888100001234 by task test_progs/123 -5-[ 20.000003] -6-[ 20.000004] CPU: 0 PID: 123 Comm: test_progs -7-[ 20.000005] Call Trace: -8-[ 20.000006] -9-[ 20.000007] dump_stack_lvl+0x60/0x80 -10-[ 20.000008] print_report+0xc4/0x630 -11-[ 20.000009] kasan_report+0xb6/0xf0 -12-[ 20.000010] -13-[ 20.000011] ================================================================== -::error title=kernel_splats::kernel splat detected, see the dmesg.txt artifact diff --git a/run-vmtest/tests/check_kernel_splats/cases/kasan/expected-splat-log.txt b/run-vmtest/tests/check_kernel_splats/cases/kasan/expected-splat-log.txt new file mode 100644 index 0000000..0fdae83 --- /dev/null +++ b/run-vmtest/tests/check_kernel_splats/cases/kasan/expected-splat-log.txt @@ -0,0 +1,14 @@ +kernel splat detected: [ 20.000001] BUG: KASAN: slab-use-after-free in foo+0x42/0x100 +1-[ 0.000000] Linux version 6.5.0 +2-[ 20.000000] ================================================================== +3:[ 20.000001] BUG: KASAN: slab-use-after-free in foo+0x42/0x100 +4-[ 20.000002] Read of size 8 at addr ffff888100001234 by task test_progs/123 +5-[ 20.000003] +6-[ 20.000004] CPU: 0 PID: 123 Comm: test_progs +7-[ 20.000005] Call Trace: +8-[ 20.000006] +9-[ 20.000007] dump_stack_lvl+0x60/0x80 +10-[ 20.000008] print_report+0xc4/0x630 +11-[ 20.000009] kasan_report+0xb6/0xf0 +12-[ 20.000010] +13-[ 20.000011] ================================================================== diff --git a/run-vmtest/tests/check_kernel_splats/cases/mixed_allowlist/allowlist.txt b/run-vmtest/tests/check_kernel_splats/cases/mixed_allowlist/allowlist.txt new file mode 100644 index 0000000..2d5c5f0 --- /dev/null +++ b/run-vmtest/tests/check_kernel_splats/cases/mixed_allowlist/allowlist.txt @@ -0,0 +1 @@ +WARNING: CPU: 0 PID: 100 at kernel/sched/core\.c:1234 diff --git a/run-vmtest/tests/check_kernel_splats/cases/mixed_allowlist/dmesg.txt b/run-vmtest/tests/check_kernel_splats/cases/mixed_allowlist/dmesg.txt new file mode 100644 index 0000000..cb19372 --- /dev/null +++ b/run-vmtest/tests/check_kernel_splats/cases/mixed_allowlist/dmesg.txt @@ -0,0 +1,5 @@ +[ 0.000000] Linux version 6.5.0 +[ 10.000000] WARNING: CPU: 0 PID: 100 at kernel/sched/core.c:1234 allowed+0x1/0x2 +[ 10.000001] Call Trace: +[ 11.000000] BUG: KASAN: slab-out-of-bounds in real_splat+0x3/0x4 +[ 11.000001] Read of size 8 at addr ffff888000000000 by task test_progs/9 diff --git a/run-vmtest/tests/check_kernel_splats/cases/mixed_allowlist/env b/run-vmtest/tests/check_kernel_splats/cases/mixed_allowlist/env new file mode 100644 index 0000000..1a6185b --- /dev/null +++ b/run-vmtest/tests/check_kernel_splats/cases/mixed_allowlist/env @@ -0,0 +1 @@ +export SPLAT_ALLOWLIST_FILE="${CASE_DIR}/allowlist.txt" diff --git a/run-vmtest/tests/check_kernel_splats/cases/mixed_allowlist/expected-output.txt b/run-vmtest/tests/check_kernel_splats/cases/mixed_allowlist/expected-output.txt new file mode 100644 index 0000000..c5e0ac9 --- /dev/null +++ b/run-vmtest/tests/check_kernel_splats/cases/mixed_allowlist/expected-output.txt @@ -0,0 +1,4 @@ +::group::kernel_splats - Checking kernel log for splats +Splat denylist: $VMTEST_CONFIGS/SPLAT_DENYLIST +Splat allowlist: $CASE_DIR/allowlist.txt +::endgroup:: diff --git a/run-vmtest/tests/check_kernel_splats/cases/mixed_allowlist/expected-splat-log.txt b/run-vmtest/tests/check_kernel_splats/cases/mixed_allowlist/expected-splat-log.txt new file mode 100644 index 0000000..1800321 --- /dev/null +++ b/run-vmtest/tests/check_kernel_splats/cases/mixed_allowlist/expected-splat-log.txt @@ -0,0 +1,6 @@ +kernel splat detected: [ 11.000000] BUG: KASAN: slab-out-of-bounds in real_splat+0x3/0x4 +1-[ 0.000000] Linux version 6.5.0 +2-[ 10.000000] WARNING: CPU: 0 PID: 100 at kernel/sched/core.c:1234 allowed+0x1/0x2 +3-[ 10.000001] Call Trace: +4:[ 11.000000] BUG: KASAN: slab-out-of-bounds in real_splat+0x3/0x4 +5-[ 11.000001] Read of size 8 at addr ffff888000000000 by task test_progs/9 diff --git a/run-vmtest/tests/check_kernel_splats/cases/mixed_allowlist/expected-status.txt b/run-vmtest/tests/check_kernel_splats/cases/mixed_allowlist/expected-status.txt new file mode 100644 index 0000000..e78f9fa --- /dev/null +++ b/run-vmtest/tests/check_kernel_splats/cases/mixed_allowlist/expected-status.txt @@ -0,0 +1 @@ +kernel_splats:1 diff --git a/run-vmtest/tests/check_kernel_splats/cases/multi/expected-output.txt b/run-vmtest/tests/check_kernel_splats/cases/multi/expected-output.txt index cffc0bd..d1c6439 100644 --- a/run-vmtest/tests/check_kernel_splats/cases/multi/expected-output.txt +++ b/run-vmtest/tests/check_kernel_splats/cases/multi/expected-output.txt @@ -2,18 +2,3 @@ Splat denylist: $VMTEST_CONFIGS/SPLAT_DENYLIST Splat allowlist: $VMTEST_CONFIGS/SPLAT_ALLOWLIST ::endgroup:: -1-[ 0.100000] Linux version 6.5.0 -2:[ 10.000000] WARNING: CPU: 0 PID: 100 at kernel/sched/core.c:1 first+0x1/0x2 -3-[ 10.000001] Call Trace: -4-[ 10.000002] ? __warn+0x80/0xc0 -5-[ 10.000003] ---[ end trace ]--- -6-[ 10.500000] test_progs: PASS one -7-[ 11.000000] test_progs: running two -8:[ 11.000001] BUG: KASAN: slab-out-of-bounds in second+0x3/0x4 -9-[ 11.000002] Read of size 8 at addr ffff888000000000 by task test_progs/9 -10-[ 11.000003] ---[ end trace ]--- -11-[ 199.000000] test_progs: running three -12:[ 200.000000] watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [test_progs:9] -13:[ 200.000001] watchdog: BUG: soft lockup - CPU#1 stuck for 22s! [test_progs:9] -14-[ 201.000000] test_progs: PASS -::error title=kernel_splats::kernel splat detected, see the dmesg.txt artifact diff --git a/run-vmtest/tests/check_kernel_splats/cases/multi/expected-splat-log.txt b/run-vmtest/tests/check_kernel_splats/cases/multi/expected-splat-log.txt new file mode 100644 index 0000000..fdd6b26 --- /dev/null +++ b/run-vmtest/tests/check_kernel_splats/cases/multi/expected-splat-log.txt @@ -0,0 +1,15 @@ +kernel splat detected: [ 10.000000] WARNING: CPU: 0 PID: 100 at kernel/sched/core.c:1 first+0x1/0x2 +1-[ 0.100000] Linux version 6.5.0 +2:[ 10.000000] WARNING: CPU: 0 PID: 100 at kernel/sched/core.c:1 first+0x1/0x2 +3-[ 10.000001] Call Trace: +4-[ 10.000002] ? __warn+0x80/0xc0 +5-[ 10.000003] ---[ end trace ]--- +6-[ 10.500000] test_progs: PASS one +7-[ 11.000000] test_progs: running two +8:[ 11.000001] BUG: KASAN: slab-out-of-bounds in second+0x3/0x4 +9-[ 11.000002] Read of size 8 at addr ffff888000000000 by task test_progs/9 +10-[ 11.000003] ---[ end trace ]--- +11-[ 199.000000] test_progs: running three +12:[ 200.000000] watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [test_progs:9] +13:[ 200.000001] watchdog: BUG: soft lockup - CPU#1 stuck for 22s! [test_progs:9] +14-[ 201.000000] test_progs: PASS diff --git a/run-vmtest/tests/check_kernel_splats/cases/no_denylist/expected-splat-log.txt b/run-vmtest/tests/check_kernel_splats/cases/no_denylist/expected-splat-log.txt new file mode 100644 index 0000000..dc7c4a4 --- /dev/null +++ b/run-vmtest/tests/check_kernel_splats/cases/no_denylist/expected-splat-log.txt @@ -0,0 +1 @@ +No splat denylist: SPLAT_DENYLIST_FILE=/nonexistent/SPLAT_DENYLIST diff --git a/run-vmtest/tests/check_kernel_splats/cases/unconfigured/dmesg.txt b/run-vmtest/tests/check_kernel_splats/cases/unconfigured/dmesg.txt new file mode 100644 index 0000000..56a30cb --- /dev/null +++ b/run-vmtest/tests/check_kernel_splats/cases/unconfigured/dmesg.txt @@ -0,0 +1,2 @@ +[ 0.000000] Linux version 6.5.0 +[ 12.345679] WARNING: CPU: 0 PID: 100 at kernel/sched/core.c:1234 do_thing+0x10/0x20 diff --git a/run-vmtest/tests/check_kernel_splats/cases/unconfigured/env b/run-vmtest/tests/check_kernel_splats/cases/unconfigured/env new file mode 100644 index 0000000..3dfcc6d --- /dev/null +++ b/run-vmtest/tests/check_kernel_splats/cases/unconfigured/env @@ -0,0 +1,2 @@ +export SPLAT_DENYLIST_FILE="${CASE_DIR}/missing-denylist.txt" +export SPLAT_ALLOWLIST_FILE="${CASE_DIR}/missing-allowlist.txt" diff --git a/run-vmtest/tests/check_kernel_splats/cases/unconfigured/expected-output.txt b/run-vmtest/tests/check_kernel_splats/cases/unconfigured/expected-output.txt new file mode 100644 index 0000000..8163cc7 --- /dev/null +++ b/run-vmtest/tests/check_kernel_splats/cases/unconfigured/expected-output.txt @@ -0,0 +1 @@ +Skipping kernel splat check: no allowlist or denylist files found diff --git a/run-vmtest/tests/check_kernel_splats/cases/unconfigured/expected-status.txt b/run-vmtest/tests/check_kernel_splats/cases/unconfigured/expected-status.txt new file mode 100644 index 0000000..e69de29 diff --git a/run-vmtest/tests/check_kernel_splats/cases/warn/expected-output.txt b/run-vmtest/tests/check_kernel_splats/cases/warn/expected-output.txt index 2b4221e..d1c6439 100644 --- a/run-vmtest/tests/check_kernel_splats/cases/warn/expected-output.txt +++ b/run-vmtest/tests/check_kernel_splats/cases/warn/expected-output.txt @@ -2,18 +2,3 @@ Splat denylist: $VMTEST_CONFIGS/SPLAT_DENYLIST Splat allowlist: $VMTEST_CONFIGS/SPLAT_ALLOWLIST ::endgroup:: -1-[ 0.000000] Linux version 6.5.0 -2-[ 0.001234] CPU: 0 -3-[ 12.345678] ------------[ cut here ]------------ -4:[ 12.345679] WARNING: CPU: 0 PID: 100 at kernel/sched/core.c:1234 do_thing+0x10/0x20 -5-[ 12.345680] Modules linked in: -6-[ 12.345681] CPU: 0 PID: 100 Comm: test_progs -7-[ 12.345682] RIP: 0010:do_thing+0x10/0x20 -8-[ 12.345683] Call Trace: -9-[ 12.345684] -10-[ 12.345685] ? __warn+0x80/0xc0 -11-[ 12.345686] ? report_bug+0xa0/0xc0 -12-[ 12.345687] -13-[ 12.345688] ---[ end trace ]--- -14-[ 13.000000] test_progs: PASS -::error title=kernel_splats::kernel splat detected, see the dmesg.txt artifact diff --git a/run-vmtest/tests/check_kernel_splats/cases/warn/expected-splat-log.txt b/run-vmtest/tests/check_kernel_splats/cases/warn/expected-splat-log.txt new file mode 100644 index 0000000..4d6d65b --- /dev/null +++ b/run-vmtest/tests/check_kernel_splats/cases/warn/expected-splat-log.txt @@ -0,0 +1,15 @@ +kernel splat detected: [ 12.345679] WARNING: CPU: 0 PID: 100 at kernel/sched/core.c:1234 do_thing+0x10/0x20 +1-[ 0.000000] Linux version 6.5.0 +2-[ 0.001234] CPU: 0 +3-[ 12.345678] ------------[ cut here ]------------ +4:[ 12.345679] WARNING: CPU: 0 PID: 100 at kernel/sched/core.c:1234 do_thing+0x10/0x20 +5-[ 12.345680] Modules linked in: +6-[ 12.345681] CPU: 0 PID: 100 Comm: test_progs +7-[ 12.345682] RIP: 0010:do_thing+0x10/0x20 +8-[ 12.345683] Call Trace: +9-[ 12.345684] +10-[ 12.345685] ? __warn+0x80/0xc0 +11-[ 12.345686] ? report_bug+0xa0/0xc0 +12-[ 12.345687] +13-[ 12.345688] ---[ end trace ]--- +14-[ 13.000000] test_progs: PASS diff --git a/run-vmtest/tests/check_kernel_splats/run-test.sh b/run-vmtest/tests/check_kernel_splats/run-test.sh index f3a5f79..4143198 100755 --- a/run-vmtest/tests/check_kernel_splats/run-test.sh +++ b/run-vmtest/tests/check_kernel_splats/run-test.sh @@ -11,6 +11,7 @@ run_case() ( CASE_DIR=$(realpath "${case_dir}") export CASE_DIR OUTPUT_DIR="$tmpdir" STATUS_FILE="$tmpdir/exitstatus" + : > "${STATUS_FILE}" # Default to the configs this repo carries, which is what a job gets from # $VMTEST_CONFIGS. A case overrides either one through its `env` file. @@ -30,6 +31,13 @@ run_case() ( diff -u "${case_dir}/expected-output.txt" "$tmpdir/output.txt" diff -u "${case_dir}/expected-status.txt" "$tmpdir/exitstatus" + + if [ -f "${case_dir}/expected-splat-log.txt" ]; then + diff -u "${case_dir}/expected-splat-log.txt" "$tmpdir/kernel_splats.log" + elif [ -e "$tmpdir/kernel_splats.log" ]; then + echo "Unexpected kernel_splats.log for ${case_dir}" + return 1 + fi ) for case_dir in cases/*/; do