Files
cozystack/hack/run-kubernetes-runner-cpu_test.bats
Myasnikov Daniil cc942fed68 test(tests): run unit suites with Bats and retain POSIX coverage
The shell translator rewrites test bodies and loses Bats reporting.
The unit lane needs complete TAP results and JUnit reports without
changing how live-cluster suites run.

Sourced production helpers still need a dash pass, and unit test bodies
need nounset without exporting shell options into subprocesses.

Assisted-by: LLM
Signed-off-by: Myasnikov Daniil <myasnikovdaniil2001@gmail.com>
2026-10-07 11:04:00 +03:00

1436 lines
58 KiB
Bash

#!/usr/bin/env bats
# Regression coverage for the two readings that price the layers ABOVE the
# sandbox nodes, in hack/e2e-chainsaw/_lib/run-kubernetes.sh: the runner
# kernel's own /proc/stat, and the QEMU threads of the sandbox VMs. cozytest.sh
# ends an @test block at the first bare closing brace, so command mocks stay at
# top level.
#
# What these two answer, and why nothing beside them answers it. Every other CPU
# reading in that file has a subject inside the sandbox -- a cgroup, a tenant
# worker's threads, a sandbox node's own /proc/stat -- and each of them can say a
# guest was given its ticks while getting no work done. None can say what the
# layers above spent, and that is where this suite's own tax is paid: the sandbox
# nodes' guest time is charged to the runner kernel as user time, and whatever
# the runner VM loses to the machine hosting IT is charged to nobody the sandbox
# can see. /proc/stat is not namespaced, so reading it from this container reads
# the runner kernel; the sandbox VMs are QEMU processes in this container's own
# PID namespace, so their threads are a local read too.
#
# So the failure these guard against is not a wrong number. It is a capture that
# reads the wrong layer, or an empty directory that a reader takes for a machine
# that spent nothing -- and the legends, which are what stop a reader comparing a
# hypervisor's row against its guest's.
#
# Run from the repo root with `make bats-unit-tests`, or directly with
# `bats hack/run-kubernetes-runner-cpu_test.bats`. The legacy
# `hack/cozytest.sh` runner remains a supported compatibility path.
load test_helper
timeout_calls=/dev/null
timeout_rc_override=
timeout() {
local command_rc=0
printf '%s\n' "$*" >>"${timeout_calls}"
# Return 97 rather than running the command when the wrapper is not the
# bounded form: a read that lost its ceiling must not pass as a read.
[ "${1:-}" = -k ] || return 97
shift 3
"$@" || command_rc=$?
[ -z "${timeout_rc_override}" ] || return "${timeout_rc_override}"
return "${command_rc}"
}
assert_file_contains() {
local needle="$1"
local file="$2"
if [ ! -f "${file}" ]; then
printf 'expected %s to exist so it could be checked for: %s\n' "${file}" "${needle}" >&2
return 1
fi
case "$(cat "${file}")" in
*"${needle}"*) return 0 ;;
esac
printf 'expected %s to contain: %s\n' "${file}" "${needle}" >&2
cat "${file}" >&2
return 1
}
assert_file_lacks_pattern() {
local pattern="$1"
local file="$2"
# A missing file must fail rather than vacuously pass: a bare `! grep -q`
# succeeds on an unreadable path, which is indistinguishable from "the file
# exists and does not carry the label".
if [ ! -f "${file}" ]; then
printf 'expected %s to exist so it could be checked for: %s\n' "${file}" "${pattern}" >&2
return 1
fi
# Branched on awk's exact status. awk exits 1 for "no line matched" and 2 for
# "I could not evaluate this"; folded together, a negative assertion is
# satisfied by its own matcher giving up, which is the direction that goes
# green and stays green.
local _rc=0
awk -v pattern="${pattern}" '$0 ~ pattern { found = 1 } END { exit found ? 0 : 1 }' "${file}" || _rc=$?
case "${_rc}" in
0)
printf 'expected %s not to match: %s\n' "${file}" "${pattern}" >&2
cat "${file}" >&2
return 1
;;
1) return 0 ;;
*)
printf 'awk could not evaluate pattern %s against %s\n' "${pattern}" "${file}" >&2
return 1
;;
esac
}
# The functions under test redirect a command's stderr into a report file and
# decide which artifact to write from it. cozytest.sh runs under `set -x`, so the
# tracer's own line for that command lands on the very stderr being redirected,
# and every assertion about those files would be reading the tracer. Call through
# these wrappers so the sinks hold what production writes.
run_kernel_capture() {
local _rc=0
( set +x; cozy_capture_runner_kernel_cpu_time "${1:-1}" ) || _rc=$?
return "${_rc}"
}
run_thread_capture() {
local _rc=0
( set +x; cozy_capture_sandbox_qemu_thread_cpu "${1:-1}" ) || _rc=$?
return "${_rc}"
}
# A /proc/stat shaped like the kernel's: the summed row first, one row per CPU,
# then the rows that are not CPU time at all. Two CPU rows are enough to tell the
# summed row from a per-CPU one; the walk does not count them.
#
# The numbers are the ones a loaded hypervisor produces: most of user here is
# guest, staged so the guest-inside-user accounting rule has something to bite
# on. How much of user is guest on a real runner is not a claim this fixture
# makes; the runner also runs the CI process tree, containerd and the suite.
stage_proc_stat() {
local file="$1"
mkdir -p "$(dirname "${file}")"
{
printf 'cpu 9000000 120 800000 4000000 30000 0 9000 45000 8900000 0\n'
printf 'cpu0 4500000 60 400000 2000000 15000 0 4500 22000 4450000 0\n'
printf 'cpu1 4500000 60 400000 2000000 15000 0 4500 23000 4450000 0\n'
printf 'intr 900000000 0 0 0\n'
printf 'ctxt 1800000000\n'
printf 'btime 1700000000\n'
printf 'processes 4000000\n'
} >"${file}"
}
# A /proc shaped like this container's: three QEMU processes, each with an
# emulator thread and two vCPU threads. The vCPU thread name carries a space
# inside its parentheses, which is the whole reason the legend tells a reader to
# parse from the last ) -- a fixture without it would let a field-counting reader
# pass.
stage_sandbox_proc() {
local root="$1"
local pid tid
for pid in 101 202 303; do
mkdir -p "${root}/${pid}/task/${pid}"
printf 'qemu-system-x86_64\n' >"${root}/${pid}/comm"
printf '%s (qemu-system-x86) S 1 %s %s 0 -1 0 0 0 0 0 700 300 0 0 20 0 9 0 100 0 0\n' \
"${pid}" "${pid}" "${pid}" >"${root}/${pid}/task/${pid}/stat"
for tid in 1 2; do
mkdir -p "${root}/${pid}/task/${pid}${tid}"
printf '%s%s (CPU %s/KVM) R 1 %s %s 0 -1 0 0 0 0 0 5000 900 0 0 20 0 9 0 100 0 0\n' \
"${pid}" "${tid}" "$((tid - 1))" "${pid}" "${pid}" \
>"${root}/${pid}/task/${pid}${tid}/stat"
done
done
# A process that is not QEMU, so the probe's filter is exercised rather than
# assumed: this container also runs the shell driving the suite.
mkdir -p "${root}/9/task/9"
printf 'bash\n' >"${root}/9/comm"
printf '9 (bash) S 1 9 9 0 -1 0 0 0 0 0 4 2 0 0 20 0 1 0 100 0 0\n' >"${root}/9/task/9/stat"
}
stage() {
COZY_REPORT_DIR="$1/report"
COZY_SNAPSHOT_NAME=runner-cpu-smoke
COZY_DIAG_RUNNER_PROC_STAT="$1/proc-stat"
COZY_DIAG_SANDBOX_PROC="$1/proc"
stage_proc_stat "$COZY_DIAG_RUNNER_PROC_STAT"
stage_sandbox_proc "$COZY_DIAG_SANDBOX_PROC"
}
kernel_path() {
printf '%s/snapshots/runner-cpu-smoke/runner-kernel-cpu-time/sample-%s/proc-stat.txt' \
"${COZY_REPORT_DIR}" "${1:-1}"
}
threads_path() {
printf '%s/snapshots/runner-cpu-smoke/sandbox-qemu-thread-cpu/sample-%s/qemu-threads.txt' \
"${COZY_REPORT_DIR}" "${1:-1}"
}
# ---------------------------------------------------------------------------
# The runner kernel's own CPU time.
# ---------------------------------------------------------------------------
@test "the runner kernel CPU rows reach the capture" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
run_kernel_capture
capture=$(kernel_path)
assert_file_contains 'cpu 9000000 120 800000' "$capture"
assert_file_contains 'cpu0 4500000' "$capture"
rm -rf "$tmp"
}
@test "the capture says which layer its rows belong to" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
run_kernel_capture
# The one reading that inverts every conclusion drawn from this file. Two
# kernels in this report publish a /proc/stat -- the runner, and each sandbox
# node one layer down -- so a reader who takes these rows for a sandbox node is
# comparing a hypervisor against its own guest. The tenant worker has no
# /proc/stat capture at all, which the legend now says rather than implying a
# third file to go looking for.
capture=$(kernel_path)
assert_file_contains 'these rows belong to the RUNNER VM kernel' "$capture"
assert_file_contains 'one layer above the sandbox nodes' "$capture"
assert_file_contains 'sandbox-host-cpu-time' "$capture"
# And that there is no third /proc/stat to go looking for. The clause sits in
# parallel with one that names a directory, so an earlier wording sent a reader
# hunting a tenant-worker /proc/stat that no capture in this report takes.
assert_file_contains 'no capture in this report reads /proc/stat inside a tenant worker at all' "$capture"
rm -rf "$tmp"
}
@test "the layer legend does not invent a capture that the report does not take" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
run_kernel_capture
# The two claims the legend makes about other readers, each pinned to the
# source rather than to a count of the string: counting mentions of the file
# also counts the legend itself, so a legend inventing a third reader kept
# the count green (M21).
capture=$(kernel_path)
lib=hack/e2e-chainsaw/_lib/run-kubernetes.sh
awk '/^cozy_capture_sandbox_node_cpu_time\(\)/,/^}/' "$lib" | grep -q 'read /proc/stat' || {
echo "FAIL: the legend points one layer down at a collector that no longer reads /proc/stat"
false
}
if grep -n 'tenantkubeconfig' "$lib" | grep -q 'proc/stat'; then
echo "FAIL: something reads /proc/stat through a tenant kubeconfig; the legend denies exactly that"
false
fi
assert_file_lacks_pattern 'a tenant worker reports its own' "$capture"
rm -rf "$tmp"
}
@test "the column legend travels with the numbers" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
run_kernel_capture
capture=$(kernel_path)
# The column order, because the eighth and ninth are the two a reader wants
# and are adjacent.
assert_file_contains 'user nice system idle iowait irq softirq steal guest guest_nice' "$capture"
# The two ordinals, by number rather than by the order of the words above: the
# eighth and the ninth are adjacent and are the two a reader actually wants, so
# a swapped pair turns a fraction of a percent of steal into twenty-odd. Pinned
# because the column-order string alone stays green when the ordinals swap.
assert_file_contains 'The eighth number is steal and the ninth is guest' "$capture"
# And the accounting rule that makes this layer different from the one below:
# guest is inside user, so adding them double-counts. Deliberately NOT a claim
# about what fraction of this kernel's user time is guest -- the runner also
# runs the CI process tree, and these rows are read against nothing that could
# establish a proportion.
assert_file_contains 'already counted inside user' "$capture"
assert_file_lacks_pattern 'nearly all' "$capture"
rm -rf "$tmp"
}
@test "the legend says what steal means on this layer and nowhere else" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
run_kernel_capture
# This is the number the whole capture exists for. A sandbox node reporting
# steal 0 says the runner kernel served it promptly and says nothing about
# whether the runner VM was itself waiting on the machine hosting it -- and
# that second number appears in no other file in this report.
capture=$(kernel_path)
assert_file_contains 'steal on THIS layer' "$capture"
assert_file_contains 'gave to somebody else' "$capture"
# And read in ONE direction. A climbing steal proves this runner VM was
# preempted; a zero proves nothing, because the column is filled only where the
# hypervisor exposes a paravirt steal clock and this capture observes neither
# the hypervisor nor that clock. The sandbox nodes one layer down can make the
# stronger claim because this repository starts them with accel=kvm; nobody
# here starts the runner VM.
assert_file_contains 'read that column in ONE direction only' "$capture"
assert_file_contains 'paravirt steal clock' "$capture"
assert_file_lacks_pattern 'A steal of zero here is a reading and not an absence' "$capture"
rm -rf "$tmp"
}
@test "the legend warns that the per-CPU rows are not physical cores" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
run_kernel_capture
# A cpuN row is a CPU as this kernel sees it, which is a hardware thread
# wherever SMT is exposed. The capture reads no topology, so it says where that
# answer lives rather than asserting which this lane is -- an artifact confident
# about a machine it never looked at is worse than one that names the gap.
capture=$(kernel_path)
assert_file_contains 'What the row count is not is a core count' "$capture"
assert_file_contains 'thread_siblings_list' "$capture"
assert_file_lacks_pattern 'the lane runs SMT' "$capture"
# And the online/possible split, which is why the rows can be fewer than the
# total is summed over.
assert_file_contains 'one per ONLINE CPU' "$capture"
rm -rf "$tmp"
}
@test "the runner kernel read is bounded and keeps its exit code" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
run_kernel_capture
# Local does not mean instant: this runs on the failure path of a machine
# already wedged enough to lose a node join, and /proc is served by that same
# kernel.
assert_file_contains "-k 5 20 cat" "$timeout_calls"
assert_file_contains '[capture exit code: 0]' "$(kernel_path)"
rm -rf "$tmp"
}
@test "a lowered read budget moves the runner kernel bound" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
# Set after sourcing, which is how a caller and a test both set it. A value
# read only at assignment time would reach `timeout` unchecked here.
COZY_DIAG_READ_TIMEOUT=4
run_kernel_capture
assert_file_contains '-k 5 4 cat' "$timeout_calls"
rm -rf "$tmp"
}
@test "a zero read budget is corrected rather than disabling the bound" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
# `timeout -k 5 0` disables the timeout outright, so a zero assigned after
# sourcing would restore the unbounded read this bound exists to remove.
COZY_DIAG_READ_TIMEOUT=0
run_kernel_capture
assert_file_lacks_pattern '^-k 5 0 ' "$timeout_calls"
assert_file_contains "-k 5 $COZY_DIAG_READ_TIMEOUT_DEFAULT cat" "$timeout_calls"
rm -rf "$tmp"
}
@test "each runner kernel reading records when it was taken" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
run_kernel_capture
# This pair is not taken inside one diagnostics block: the first reading is
# taken before the node-join wait and the second only when that wait has run
# out, so the interval between them is the whole join window rather than a
# knob. A /proc/stat row carries no sample time, so nothing else in the
# artifact records it.
capture=$(kernel_path)
stamp=$(sed -n 's/.*read attempted from \([0-9][0-9]*\) to \([0-9][0-9]*\) epoch seconds.*/\1 \2/p' "$capture")
if [ -z "$stamp" ]; then
echo "expected a bare epoch stamp in $capture" >&2
cat "$capture" >&2
return 1
fi
rm -rf "$tmp"
}
@test "the sample number decides which runner kernel reading a file is" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
run_kernel_capture 2
# The pair is the instrument: one reading of a running total is an average over
# the machine's whole uptime, not a rate over the failure. Two readings filed
# under the same name would leave the second overwriting the first and the
# artifact reading like a single sample.
assert_file_contains 'cpu 9000000' "$(kernel_path 2)"
[ ! -f "$(kernel_path 1)" ]
rm -rf "$tmp"
}
@test "a file holding no cpu row at all is not filed as a reading" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
# /proc/stat carries intr, ctxt and btime as well, so a read cut off before the
# cpu rows leaves a file with numbers in it and no CPU time at all. Keyed on
# size, that would be filed as a reading and the caller told a pair exists.
{
printf 'intr 900000000 0 0 0\n'
printf 'ctxt 1800000000\n'
} >"$COZY_DIAG_RUNNER_PROC_STAT"
rc=0
run_kernel_capture || rc=$?
[ "$rc" -ne 0 ]
capture=$(kernel_path)
# `cat` exits zero for any file it could open, so this arrives on the CLEAN
# exit path: the read did not fail, the file simply carries no CPU time. Said
# in the file, because an empty-looking capture with exit code 0 otherwise
# reads as a kernel that was idle.
assert_file_contains 'the read completed and returned no cpu row at all' "$capture"
assert_file_contains 'not a reading that the runner kernel was idle' "$capture"
# And the pairing instruction must not ride on it: telling a reader to subtract
# two files asserts both hold a reading, and following it here turns the
# sibling's whole cumulative total into a rate over the window.
assert_file_lacks_pattern 'subtracting this file from its sibling' "$capture"
rm -rf "$tmp"
}
@test "a read that returned nothing is reported to the caller, not only to the report" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
# Killed before it produced a byte: the dominant shape of a bounded read that
# ran out. Both callers ask this function whether it collected anything, and
# one of them runs on the passing path where the report is the artifact nobody
# downloads -- so a capture that got nothing has to answer non-zero or the
# warning saying the pair is broken never prints.
rm -f "$COZY_DIAG_RUNNER_PROC_STAT"
rc=0
run_kernel_capture || rc=$?
[ "$rc" -ne 0 ]
# The arm this staging reaches, not the substring all three unavailable arms
# share: cat on a missing file fails with a message, so the note must point
# at the failure marker holding it.
assert_file_contains 'what it said is in the COLLECTION-FAILED.txt' "$(kernel_path)"
rm -rf "$tmp"
}
@test "a kernel read that failed without a word says so, not something else" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
# The fourth corner: non-zero status, no rows, and silence on both streams.
# Staged with an empty stat file and a forced status, since a real cat that
# fails always says why. Unstaged, this arm and its wording were deletable
# with the suite green.
: >"$COZY_DIAG_RUNNER_PROC_STAT"
timeout_rc_override=124
rc=0
run_kernel_capture || rc=$?
timeout_rc_override=
[ "$rc" -ne 0 ]
assert_file_contains 'said nothing on either stream' "$(kernel_path)"
rm -rf "$tmp"
}
@test "a thread walk that failed without a word says so, not something else" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
# The probe is stubbed to a silent non-zero exit: every real shape of the
# probe leaves either thread lines or a finding, so the silent corner is
# reachable only when the walk itself dies wordlessly.
_cozy_thread_cpu_probe() { printf 'exit 3'; }
rc=0
run_thread_capture || rc=$?
[ "$rc" -ne 0 ]
capture=$(threads_path)
assert_file_contains 'said nothing on either stream' "$capture"
rm -rf "$tmp"
}
@test "a runner kernel read cut off part way is marked incomplete, not whole" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
# The walk wrote rows and then the wrapper killed it: the shape where a
# whole-looking file is most misleading, since the difference against its
# sibling would understate every row the read never reached.
timeout_rc_override=124
run_kernel_capture || true
capture=$(kernel_path)
assert_file_contains 'cpu 9000000' "$capture"
assert_file_contains 'incomplete' "$capture"
assert_file_lacks_pattern 'subtracting this file from its sibling' "$capture"
assert_file_contains '[capture exit code: 124]' "$capture"
# The lines that say how to read the numbers stay, because they do not depend
# on the read having finished and this is exactly where a reader needs them.
assert_file_contains 'RUNNER VM kernel' "$capture"
rm -rf "$tmp"
}
@test "a partial runner kernel read is not reported to the caller as nothing" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
# The other half of the pair above, and the reason the status is decided by
# what reached the file rather than by the exit code alone: a read cut off
# after it wrote rows left a usable capture, and a caller told nothing was
# collected would contradict the file sitting beside it.
timeout_rc_override=124
rc=0
run_kernel_capture || rc=$?
[ "$rc" -eq 0 ]
rm -rf "$tmp"
}
@test "a warning beside a healthy runner kernel read is not filed as a failure" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
# A read that succeeds and still says something, which is the shape kubectl and
# talosctl produce all over this collector's neighbourhood. Staged as a `cat`
# on PATH rather than mocked as a function, because the collector runs it
# through the `timeout` wrapper, which resolves it as a command.
#
# Which file the complaint lands in is decided by the STATUS, not by whether
# stderr holds anything, so a healthy capture keeps its warning instead of
# shipping a failure marker beside a reading that succeeded.
mkdir -p "$tmp/bin"
cat >"$tmp/bin/cat" <<'STUB'
#!/bin/sh
printf 'cat: (hint) this file is served by a pseudo filesystem\n' >&2
while IFS= read -r line || [ -n "$line" ]; do printf '%s\n' "$line"; done <"$1"
STUB
chmod +x "$tmp/bin/cat"
PATH="$tmp/bin:$PATH"
run_kernel_capture
dir="$COZY_REPORT_DIR/snapshots/runner-cpu-smoke/runner-kernel-cpu-time/sample-1"
assert_file_contains 'cpu 9000000' "$dir/proc-stat.txt"
assert_file_contains 'served by a pseudo filesystem' "$dir/READ-WARNINGS.txt"
[ ! -f "$dir/COLLECTION-FAILED.txt" ]
[ ! -f "$dir/read-error.log" ]
rm -rf "$tmp"
}
@test "a failed runner kernel read sends its message to the failure marker" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
# The other side of that routing rule, and the shape a missing pseudo file
# produces: no row reached the capture and the reason exists. Sent beside the
# capture rather than into it, and named as a failure rather than as a warning,
# because this one did fail.
rm -f "$COZY_DIAG_RUNNER_PROC_STAT"
rc=0
run_kernel_capture || rc=$?
[ "$rc" -ne 0 ]
dir="$COZY_REPORT_DIR/snapshots/runner-cpu-smoke/runner-kernel-cpu-time/sample-1"
assert_file_contains 'No such file' "$dir/COLLECTION-FAILED.txt"
assert_file_contains 'COLLECTION-FAILED.txt beside this file' "$dir/proc-stat.txt"
[ ! -f "$dir/READ-WARNINGS.txt" ]
rm -rf "$tmp"
}
@test "a runner kernel report directory that cannot be created is said out loud" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
# A file where the directory has to go. Every write below it then fails, and
# without a check the capture is a silent no-op -- the empty directory this
# whole suite exists to refuse, produced by the one cause the markers cannot
# describe, because there is nowhere to write a marker.
mkdir -p "$COZY_REPORT_DIR/snapshots/runner-cpu-smoke"
printf 'not a directory\n' >"$COZY_REPORT_DIR/snapshots/runner-cpu-smoke/runner-kernel-cpu-time"
rc=0
out=$( ( set +x; cozy_capture_runner_kernel_cpu_time 1 ) 2>&1 ) || rc=$?
[ "$rc" -ne 0 ]
case "$out" in
*"could not be created"*) ;;
*)
printf 'expected the collector to say the report directory could not be created, got: %s\n' "$out" >&2
return 1
;;
esac
rm -rf "$tmp"
}
# ---------------------------------------------------------------------------
# The sandbox VMs' QEMU threads.
# ---------------------------------------------------------------------------
@test "the sandbox QEMU thread stat lines reach the capture" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
run_thread_capture
capture=$(threads_path)
# All three sandbox VMs, because the question this answers is whether the
# three nodes paid evenly: one node's vCPU threads pinned while its siblings
# idle is a different fault from three nodes evenly loaded, and the kernel row
# one layer up sums all three.
assert_file_contains 'process 101 comm qemu-system-x86_64' "$capture"
assert_file_contains 'process 202 comm qemu-system-x86_64' "$capture"
assert_file_contains 'process 303 comm qemu-system-x86_64' "$capture"
assert_file_contains '(CPU 0/KVM)' "$capture"
# And nothing that is not QEMU: this container also runs the shell driving the
# suite, and its threads are not what this measures.
assert_file_lacks_pattern '\(bash\)' "$capture"
rm -rf "$tmp"
}
@test "the thread capture says which layer its threads belong to" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
run_thread_capture
# Two captures in this report read QEMU threads and they are one layer apart:
# these are the sandbox VMs, and the ones under tenant-thread-cpu are the
# workers running inside them. Read as the wrong one, a busy hypervisor looks
# like a busy guest.
capture=$(threads_path)
assert_file_contains 'these threads belong to the SANDBOX VMs' "$capture"
assert_file_contains 'tenant-thread-cpu' "$capture"
assert_file_contains 'runner-kernel-cpu-time' "$capture"
rm -rf "$tmp"
}
@test "the thread legend says to parse from the last closing parenthesis" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
run_thread_capture
# The trap that costs a reader the exact threads this capture exists to
# identify: a vCPU thread is named `CPU 0/KVM`, that space sits inside the
# parentheses, and every field counted over whitespace after it is off by one.
capture=$(threads_path)
assert_file_contains 'Parse from the last ) in the line instead' "$capture"
assert_file_contains 'utime the 12th and stime the 13th' "$capture"
rm -rf "$tmp"
}
@test "a container with no QEMU process is a finding rather than an empty capture" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
# The sandbox VMs are what the whole run stands on, so a container running none
# of them is the most consequential thing this instrument can say -- and it
# leaves exactly the same empty directory as a collector that failed.
rm -rf "$COZY_DIAG_SANDBOX_PROC"
mkdir -p "$COZY_DIAG_SANDBOX_PROC/9/task/9"
printf 'bash\n' >"$COZY_DIAG_SANDBOX_PROC/9/comm"
printf '9 (bash) S 1 9 9 0 -1 0 0 0 0 0 4 2 0 0 20 0 1 0 100 0 0\n' \
>"$COZY_DIAG_SANDBOX_PROC/9/task/9/stat"
rc=0
run_thread_capture || rc=$?
[ "$rc" -ne 0 ]
capture=$(threads_path)
assert_file_contains 'NO-QEMU-PROCESS' "$capture"
# And the column legend must not ride on a file with no columns in it.
assert_file_lacks_pattern 'Parse from the last' "$capture"
rm -rf "$tmp"
}
@test "a proc mount that yields nothing is not reported as a container with no QEMU" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
# The two say different things about the run: one is a container that was read
# and holds no hypervisor, the other is a read that never happened. Folded
# together, a mount this collector could not open would be filed as a sandbox
# with no VMs, which is a finding about the cluster it never observed.
rm -rf "$COZY_DIAG_SANDBOX_PROC"
mkdir -p "$COZY_DIAG_SANDBOX_PROC"
rc=0
run_thread_capture || rc=$?
[ "$rc" -ne 0 ]
capture=$(threads_path)
assert_file_contains 'NO-PROC-READ' "$capture"
assert_file_lacks_pattern 'NO-QEMU-PROCESS' "$capture"
# The closing sentence follows the marker: a read that never happened must not
# close with the no-QEMU verdict, whose subject the walk never observed.
assert_file_contains 'says nothing about what the container was running' "$capture"
assert_file_lacks_pattern 'a sandbox running no QEMU' "$capture"
rm -rf "$tmp"
}
@test "a QEMU named and then gone is not filed as a reading" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
# A routine result on this failure path: the process was named and its task
# directory was gone by the time the walk reached it. Without this the capture
# holds a heading and no thread, which is enough bytes to look like a reading.
for pid in 101 202 303; do
rm -rf "$COZY_DIAG_SANDBOX_PROC/$pid/task"
done
# Pid files staged on purpose: this is the path where "which node still had a
# usable pid file" is the whole answer, so the map must print here too.
mkdir -p "$tmp/vmroot/srv1" "$tmp/vmroot/srv2" "$tmp/vmroot/srv3"
printf '101\n' >"$tmp/vmroot/srv1/qemu.pid"
printf '202\n' >"$tmp/vmroot/srv2/qemu.pid"
printf '303\n' >"$tmp/vmroot/srv3/qemu.pid"
COZY_DIAG_SANDBOX_VM_ROOT="$tmp/vmroot"
rc=0
run_thread_capture || rc=$?
[ "$rc" -ne 0 ]
capture=$(threads_path)
assert_file_contains 'NO-THREAD-LINES' "$capture"
assert_file_lacks_pattern 'Parse from the last' "$capture"
# Three QEMUs were named two lines up, so the closing sentence must read as a
# guest going away, never as a sandbox running no QEMU.
assert_file_contains 'a guest going away under the walk' "$capture"
assert_file_lacks_pattern 'a sandbox running no QEMU' "$capture"
# And the node map still prints here: which node still had a usable pid file
# is the question this path exists to answer.
assert_file_contains 'is srv' "$capture"
rm -rf "$tmp"
}
@test "the sandbox thread read is bounded and keeps its exit code" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
run_thread_capture
assert_file_contains '-k 5 20 sh -c' "$timeout_calls"
assert_file_contains '[capture exit code: 0]' "$(threads_path)"
rm -rf "$tmp"
}
@test "the sample number decides which thread reading a file is" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
run_thread_capture 2
assert_file_contains 'process 101' "$(threads_path 2)"
[ ! -f "$(threads_path 1)" ]
rm -rf "$tmp"
}
@test "a thread walk cut off part way is marked incomplete rather than whole" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
timeout_rc_override=124
run_thread_capture || true
capture=$(threads_path)
assert_file_contains 'process 101' "$capture"
assert_file_contains 'incomplete' "$capture"
assert_file_contains '[capture exit code: 124]' "$capture"
rm -rf "$tmp"
}
@test "each thread reading records when it was taken" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
run_thread_capture
capture=$(threads_path)
stamp=$(sed -n 's/.*read attempted from \([0-9][0-9]*\) to \([0-9][0-9]*\) epoch seconds.*/\1 \2/p' "$capture")
if [ -z "$stamp" ]; then
echo "expected a bare epoch stamp in $capture" >&2
cat "$capture" >&2
return 1
fi
rm -rf "$tmp"
}
@test "the thread capture reuses the probe the worker capture runs" {
# A source check, and the point is the sharing rather than the text: the probe
# already answers the two outcomes that matter here -- found QEMU, and QEMU is
# gone -- and already names the three ways it can come up short. A second copy
# would drift from this one exactly at those failure paths, which is where
# nobody looks until it matters.
lib=hack/e2e-chainsaw/_lib/run-kubernetes.sh
n=$(awk '/^cozy_capture_sandbox_qemu_thread_cpu\(\)/,/^}/' "$lib" | grep -cF '_cozy_thread_cpu_probe' || true)
[ "$n" -ge 1 ] || {
echo "FAIL: the sandbox thread capture no longer runs the shared probe"
false
}
# And that there is still exactly one probe to share.
d=$(grep -cE '^_cozy_thread_cpu_probe\(\)' "$lib" || true)
[ "$d" -eq 1 ] || {
echo "FAIL: found $d definitions of the thread probe; a second copy is the drift this test exists to refuse"
false
}
}
# ---------------------------------------------------------------------------
# Where the two readings of each pair sit.
# ---------------------------------------------------------------------------
@test "both new readings bracket the node-join wait on both paths" {
lib=hack/e2e-chainsaw/_lib/run-kubernetes.sh
# What these pairs measure is decided by where their calls sit, not by anything
# inside the collectors: /proc/stat and a thread's utime are running totals, so
# the interval a difference divides by is whatever runs between the readings.
# The same reasoning the KVM pair beside them is held to, and the same failure:
# a second reading placed after the happy-path tail prices ten to fifteen
# minutes of storage and LoadBalancer work while the capture's own legend says
# it priced the join.
# Anchored on the wait's own body rather than on its shape: `timeout Nm bash -c`
# matches more than one line in the library, and picking the first would
# re-anchor this check the day another one is added above it.
wait_line=$(awk '/^ timeout [0-9]+m bash -c/ { cand = NR; next } cand && NR == cand + 1 && /get nodes --no-headers/ { print cand; exit } { cand = 0 }' "$lib")
tail_line=$(grep -n '^ versions=\$(kubectl --kubeconfig' "$lib" | head -n 1 | cut -d: -f1)
node_table=$(grep -n "cozy_diag_read 'tenant node table'" "$lib" | head -n 1 | cut -d: -f1)
for v in wait_line tail_line node_table; do
eval "n=\$$v"
if [ -z "$n" ]; then
echo "expected to read $v from $lib; without it this guard reports success for having lost its input" >&2
return 1
fi
done
for fn in cozy_capture_runner_kernel_cpu_time cozy_capture_sandbox_qemu_thread_cpu; do
first=$(grep -n "${fn} 1" "$lib" | head -n 1 | cut -d: -f1)
# The green second reading, found as the one after the wait rather than by
# position in the file: the other call with the same argument is the failure
# block's, and picking by count would be right only while the two happen to
# be written in this order.
green=$(awk -v w="$wait_line" -v f="${fn} 2" 'NR > w && index($0, f) { print NR; exit }' "$lib")
red=$(awk -v w="$wait_line" -v f="${fn} 2" 'NR < w && index($0, f) { line = NR } END { if (line) print line }' "$lib")
for v in first green red; do
eval "n=\$$v"
if [ -z "$n" ]; then
echo "expected to find $v for $fn in $lib; without it this guard reports success for having lost its input" >&2
return 1
fi
done
if [ "$first" -ge "$wait_line" ]; then
echo "$fn's first reading (line $first) is not taken before the node-join wait (line $wait_line), so the pair does not span it" >&2
return 1
fi
if [ "$green" -le "$wait_line" ] || [ "$green" -ge "$tail_line" ]; then
echo "$fn's passing-path second reading (line $green) does not sit between the wait (line $wait_line) and the happy-path tail (line $tail_line), so the green interval is not the join window the red one is compared against" >&2
return 1
fi
if [ "$red" -ge "$node_table" ]; then
echo "$fn's failure-path second reading (line $red) is taken after the diagnostics block has started reading the cluster (line $node_table), so the red interval is the wait plus whatever those reads cost" >&2
return 1
fi
done
}
@test "the bringup names the QEMU threads the legend identifies by name" {
# The legend reads vCPU threads by the name `CPU N/KVM`, and QEMU only
# assigns those names when started with `-name ...,debug-threads=on`; without
# the flag every thread carries the bare process name and the identification
# the legend promises does not exist on this lane. Pinned on the qemu command
# line itself, non-comment lines only, so a dropped flag fails here rather
# than surfacing as an unexplained absence in production captures.
awk '/^ qemu-system-x86_64 /,/-pidfile/' hack/e2e-prepare-cluster.bats |
grep -v '^\s*#' | grep -q 'debug-threads=on' || {
echo "FAIL: hack/e2e-prepare-cluster.bats starts QEMU without debug-threads=on; the thread names the legend documents will not exist" >&2
false
}
}
@test "the pair orders mirror around the wait so the KVM interval stays exact" {
lib=hack/e2e-chainsaw/_lib/run-kubernetes.sh
# The KVM legend calls its interval the window and means it exactly; that is
# only true while nothing runs between its samples and the wait. Its first
# reading must therefore be the LAST of the three before the wait, and its
# second the FIRST after it -- on both paths. The other two legends name the
# sibling readings inside their intervals, so their order is free.
# Anchored on the wait's own body rather than on its shape: `timeout Nm bash -c`
# matches more than one line in the library, and picking the first would
# re-anchor this check the day another one is added above it.
wait_line=$(awk '/^ timeout [0-9]+m bash -c/ { cand = NR; next } cand && NR == cand + 1 && /get nodes --no-headers/ { print cand; exit } { cand = 0 }' "$lib")
[ -n "$wait_line" ] || { echo "FAIL: could not find the node-join wait"; false; }
last_before=$(awk -v w="$wait_line" 'NR < w && /^ if ! cozy_capture_(sandbox_kvm_exits|runner_kernel_cpu_time|sandbox_qemu_thread_cpu) 1; then/ { l = $0 } END { print l }' "$lib")
case "$last_before" in
*cozy_capture_sandbox_kvm_exits*) ;;
*) echo "FAIL: the reading closest to the wait from above is not the KVM pair: $last_before"; false ;;
esac
# The failure block is defined ABOVE the wait in file order and carries the
# `|| true` form its budget guard requires; the green second readings are the
# warned `if !` calls below the wait. Position in the file is the opposite of
# position in time here, which is exactly why the forms are matched too.
for scope in green red; do
if [ "$scope" = green ]; then
first_after=$(awk -v w="$wait_line" 'NR > w && /^ if ! cozy_capture_(sandbox_kvm_exits|runner_kernel_cpu_time|sandbox_qemu_thread_cpu) 2; then/ { print $0; exit }' "$lib")
else
first_after=$(awk -v w="$wait_line" 'NR < w && /^ cozy_capture_(sandbox_kvm_exits|runner_kernel_cpu_time|sandbox_qemu_thread_cpu) 2 \|\| true$/ { print $0; exit }' "$lib")
fi
case "$first_after" in
*cozy_capture_sandbox_kvm_exits*) ;;
*) echo "FAIL: the $scope second reading closest to the wait is not the KVM pair: $first_after"; false ;;
esac
done
}
@test "both new readings report a shortfall to the job log, not only to the report" {
lib=hack/e2e-chainsaw/_lib/run-kubernetes.sh
# Two of the three call sites run outside the diagnostics block, and one of
# those is the passing path -- where the report is the artifact nobody
# downloads. A capture that collected nothing there has to say so where a
# reader of a green run will see it, or the pair is silently broken for every
# red run compared against it.
for fn in cozy_capture_runner_kernel_cpu_time cozy_capture_sandbox_qemu_thread_cpu; do
n=$(grep -cE "^ if ! ${fn} [12]; then" "$lib" || true)
[ "$n" -eq 2 ] || {
echo "FAIL: $fn has $n status-checked call sites; the two outside the failure block must both warn"
false
}
done
# And the warnings say WHICH reading is missing, matched on text specific to each
# collector. Unscoped, these greps pass on the pre-existing KVM warnings, which
# carry the same two phrases: emptying all four new warning bodies then left the
# whole suite green.
for subject in "the runner kernel's CPU time" "the sandbox VMs' QEMU threads"; do
for when in before after; do
n=$(grep -cF "WARNING: ${subject} yielded no reading ${when} the node-join wait" "$lib" || true)
[ "$n" -eq 1 ] || {
echo "FAIL: found $n warnings for ${subject} ${when} the wait; each reading warns once, in its own words"
false
}
done
done
}
@test "every legend line lands as one line rather than shredded into words" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
run_kernel_capture
run_thread_capture
# Each legend is one long single-quoted shell string, and an apostrophe inside
# one ends the quote: the sentence then reaches the file as one word per line,
# every `[` unmatched, and the capture still passes any assertion that greps for
# a short phrase. This checks the shape instead -- a bracketed line opens and
# closes on the same line -- because that is what a shredded legend loses.
for capture in "$(kernel_path)" "$(threads_path)"; do
if awk '/^\[/ && $0 !~ /\]$/ { print FILENAME ": " $0; found = 1 } END { exit found ? 1 : 0 }' "$capture"; then
:
else
echo "FAIL: a bracketed legend line in $capture does not close on its own line, which is what an apostrophe inside its single quotes does to it" >&2
return 1
fi
# And some bracketed line must exist at all: a requote that drops a whole
# legend block leaves nothing for the shape check to object to.
grep -q '^\[' "$capture" || {
echo "FAIL: $capture carries no bracketed legend line at all" >&2
return 1
}
done
rm -rf "$tmp"
}
@test "the thread legend rule is executable, not just present" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
run_thread_capture
# The legend tells a reader to parse from the last `)`. Nothing pinned that the
# rule works on the lines this capture actually holds, so the fixture's space
# inside `(CPU 0/KVM)` carried no assertion at all -- it only made the comment
# sound justified. Applied here to a real captured line: after the last `)` the
# state is field 1, utime field 12, stime field 13.
line=$(grep -F '(CPU 0/KVM)' "$(threads_path)" | head -n 1)
[ -n "$line" ] || {
echo "FAIL: no vCPU thread line in the capture to apply the rule to"
false
}
tail_fields=${line##*) }
set -- $tail_fields
[ "$1" = R ] || {
echo "FAIL: field 1 after the last ) is '$1', expected the thread state"
false
}
[ "${12}" = 5000 ] || {
echo "FAIL: field 12 after the last ) is '${12}', expected utime 5000"
false
}
[ "${13}" = 900 ] || {
echo "FAIL: field 13 after the last ) is '${13}', expected stime 900"
false
}
# And that counting over whitespace from the start of the line gets it WRONG,
# which is the whole reason the rule exists: the space inside the parentheses
# shifts every later field by one.
set -- $line
[ "${14}" != 5000 ] || {
echo "FAIL: field 14 counted from the start equals utime, so this fixture no longer carries the trap the legend warns about"
false
}
rm -rf "$tmp"
}
@test "the thread capture names which sandbox node each process is" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
# The pid files hack/e2e-prepare-cluster.bats writes when it starts the guests.
# Without this map a reader has a container pid and no way to tell the
# control-plane node from a worker-carrying one -- which is the discriminating
# question, because the tenant workers sit on specific sandbox nodes.
for srv in 1 2 3; do
mkdir -p "$tmp/vmroot/srv${srv}"
done
printf '101\n' >"$tmp/vmroot/srv1/qemu.pid"
printf '202\n' >"$tmp/vmroot/srv2/qemu.pid"
printf '303\n' >"$tmp/vmroot/srv3/qemu.pid"
COZY_DIAG_SANDBOX_VM_ROOT="$tmp/vmroot"
run_thread_capture
capture=$(threads_path)
assert_file_contains '[process 101 is srv1]' "$capture"
assert_file_contains '[process 202 is srv2]' "$capture"
assert_file_contains '[process 303 is srv3]' "$capture"
assert_file_lacks_pattern 'anonymous by node' "$capture"
rm -rf "$tmp"
}
@test "a sandbox node whose pid file is gone is absent from the map, not renamed" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
# Two of three pid files, which is what a node that died during the join looks
# like from here. The map must not silently shift, since a wrong node name is
# worse than no name: a triager would go and read the wrong guest console.
mkdir -p "$tmp/vmroot/srv1" "$tmp/vmroot/srv3"
printf '101\n' >"$tmp/vmroot/srv1/qemu.pid"
printf '303\n' >"$tmp/vmroot/srv3/qemu.pid"
COZY_DIAG_SANDBOX_VM_ROOT="$tmp/vmroot"
run_thread_capture
capture=$(threads_path)
assert_file_contains '[process 101 is srv1]' "$capture"
assert_file_contains '[process 303 is srv3]' "$capture"
assert_file_lacks_pattern 'is srv2' "$capture"
# And the legend says an absent node means an unreadable pid file rather than
# leaving the gap to be read as a node that never existed.
assert_file_contains 'had no usable pid file' "$capture"
rm -rf "$tmp"
}
@test "a capture with no pid map says it is anonymous rather than implying a name" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
# No pid files at all: a sandbox created some other way, or a tree where the
# bringup wrote them elsewhere. The KVM capture beside this one discloses its
# own anonymity in exactly this situation, and a reader who has seen that one
# would otherwise take a process id here for a node identifier.
COZY_DIAG_SANDBOX_VM_ROOT="$tmp/nowhere"
run_thread_capture
capture=$(threads_path)
assert_file_contains 'anonymous by node' "$capture"
assert_file_contains 'not which of them paid what' "$capture"
assert_file_lacks_pattern 'is srv1' "$capture"
rm -rf "$tmp"
}
@test "a pid file holding something that is not a pid is skipped, not trusted" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
# A truncated or half-written pid file, which is what a guest killed during
# startup can leave. One node's file holds text and another's is empty, and
# the asserts hold both forms out of the whole map line: an empty value slid
# through validation once rendered as `[process srv1 is ]`, which a narrow
# `is srv1` pattern read as clean (the surviving mutant both reviews named).
mkdir -p "$tmp/vmroot/srv1" "$tmp/vmroot/srv2" "$tmp/vmroot/srv3"
printf '\n' >"$tmp/vmroot/srv1/qemu.pid"
printf 'not-a-pid\n' >"$tmp/vmroot/srv3/qemu.pid"
printf '202\n' >"$tmp/vmroot/srv2/qemu.pid"
COZY_DIAG_SANDBOX_VM_ROOT="$tmp/vmroot"
run_thread_capture
capture=$(threads_path)
assert_file_contains '[process 202 is srv2]' "$capture"
assert_file_lacks_pattern 'srv1' "$capture"
assert_file_lacks_pattern 'not-a-pid' "$capture"
assert_file_lacks_pattern 'is srv3' "$capture"
# Exactly one map line: nothing rendered for the two bad files in any form.
n=$(grep -c '^\[process ' "$capture" || true)
[ "$n" -eq 1 ] || {
echo "FAIL: expected exactly one map line, found $n"
grep '^\[process ' "$capture"
false
}
rm -rf "$tmp"
}
@test "a thread walk cut off after writing lines withholds the pairing instruction" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
# The half its sibling capture already pins: telling a reader to subtract two
# files asserts both hold a whole reading. A walk cut off after the first node
# would have the other two read as having spent nothing across the window,
# which is the largest wrong number this artifact could produce.
timeout_rc_override=124
run_thread_capture || true
capture=$(threads_path)
assert_file_contains 'incomplete' "$capture"
assert_file_lacks_pattern 'subtracting this file from its sibling' "$capture"
# The lines that say how to read the numbers stay: they do not depend on the
# walk having finished, and a cut-off capture is where a reader needs them.
assert_file_contains 'Parse from the last ) in the line instead' "$capture"
rm -rf "$tmp"
}
@test "a thread walk that ends clean with nothing to read says that is a finding" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
# The probe exits zero on a container it read and found no QEMU in, so this
# arrives on the clean path with an exit code of 0 under it. Left silent, the
# capture reads as a healthy reading of an idle machine -- while what it
# actually records is that the three VMs the whole run stands on are not there.
rm -rf "$COZY_DIAG_SANDBOX_PROC"
mkdir -p "$COZY_DIAG_SANDBOX_PROC/9/task/9"
printf 'bash\n' >"$COZY_DIAG_SANDBOX_PROC/9/comm"
printf '9 (bash) S 1 9 9 0 -1 0 0 0 0 0 4 2 0 0 20 0 1 0 100 0 0\n' \
>"$COZY_DIAG_SANDBOX_PROC/9/task/9/stat"
run_thread_capture || true
capture=$(threads_path)
assert_file_contains 'NO-QEMU-PROCESS' "$capture"
assert_file_contains 'the walk completed and produced no thread line at all' "$capture"
assert_file_contains 'a finding about this run rather than a shortfall of this capture' "$capture"
assert_file_lacks_pattern 'subtracting this file from its sibling' "$capture"
rm -rf "$tmp"
}
@test "a failed thread walk sends its message to the failure marker its sibling uses" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
# No thread line AND a message: the shape a walk killed against an unreadable
# proc mount produces. It goes into COLLECTION-FAILED.txt, which is the name the
# report's documentation gives the artifact-level failure marker and the name
# the runner-kernel capture writes for this same shape -- a reader sweeping the
# tarball for markers would otherwise miss this walk entirely.
mkdir -p "$tmp/bin"
cat >"$tmp/bin/sh" <<STUB
#!/bin/sh
printf 'sh: cannot open the proc mount\\n' >&2
exit 2
STUB
chmod +x "$tmp/bin/sh"
PATH="$tmp/bin:$PATH"
rc=0
run_thread_capture || rc=$?
[ "$rc" -ne 0 ]
dir="$COZY_REPORT_DIR/snapshots/runner-cpu-smoke/sandbox-qemu-thread-cpu/sample-1"
assert_file_contains 'cannot open the proc mount' "$dir/COLLECTION-FAILED.txt"
assert_file_contains 'COLLECTION-FAILED.txt beside this file' "$dir/qemu-threads.txt"
[ ! -f "$dir/read-error.log" ]
rm -rf "$tmp"
}
@test "a thread report directory that cannot be created is said out loud" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
# The one failure the markers cannot describe, because there is nowhere to put
# one. Its sibling capture has this test; this one did not, which is the same
# asymmetry as the failure marker above.
mkdir -p "$COZY_REPORT_DIR/snapshots/runner-cpu-smoke"
printf 'not a directory\n' >"$COZY_REPORT_DIR/snapshots/runner-cpu-smoke/sandbox-qemu-thread-cpu"
rc=0
out=$( ( set +x; cozy_capture_sandbox_qemu_thread_cpu 1 ) 2>&1 ) || rc=$?
[ "$rc" -ne 0 ]
case "$out" in
*"could not be created"*) ;;
*)
printf 'expected the collector to say the report directory could not be created, got: %s\n' "$out" >&2
return 1
;;
esac
rm -rf "$tmp"
}
@test "a runner kernel read that failed after writing rows points at its message" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
# Rows AND a non-zero status AND something on stderr: the fourth corner of the
# pair of questions the arms answer, and the one no test staged. Without it the
# arm that names read-error.log can be deleted with the suite green, leaving a
# reader told the reading is partial and not told where the reason went.
mkdir -p "$tmp/bin"
cat >"$tmp/bin/cat" <<'STUB'
#!/bin/sh
while IFS= read -r line || [ -n "$line" ]; do printf '%s\n' "$line"; done <"$1"
printf 'cat: the pseudo file stopped answering part way\n' >&2
exit 1
STUB
chmod +x "$tmp/bin/cat"
PATH="$tmp/bin:$PATH"
run_kernel_capture || true
dir="$COZY_REPORT_DIR/snapshots/runner-cpu-smoke/runner-kernel-cpu-time/sample-1"
assert_file_contains 'cpu 9000000' "$dir/proc-stat.txt"
assert_file_contains 'read-error.log beside this file' "$dir/proc-stat.txt"
assert_file_contains 'stopped answering part way' "$dir/read-error.log"
rm -rf "$tmp"
}
@test "a thread walk that failed after writing lines points at its message" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
# The same fourth corner on the thread side. Its arm was unreachable from this
# suite for the same reason: the only non-zero case drove the real probe, which
# leaves stderr empty.
mkdir -p "$tmp/bin"
cat >"$tmp/bin/sh" <<STUB
#!/bin/sh
printf '101 (qemu-system-x86) S 1 101 101 0 -1 0 0 0 0 0 700 300 0 0 20 0 9 0 100 0 0\\n'
printf 'sh: the proc walk stopped part way\\n' >&2
exit 1
STUB
chmod +x "$tmp/bin/sh"
PATH="$tmp/bin:$PATH"
run_thread_capture || true
dir="$COZY_REPORT_DIR/snapshots/runner-cpu-smoke/sandbox-qemu-thread-cpu/sample-1"
assert_file_contains 'incomplete' "$dir/qemu-threads.txt"
assert_file_contains 'read-error.log beside this file' "$dir/qemu-threads.txt"
assert_file_contains 'stopped part way' "$dir/read-error.log"
rm -rf "$tmp"
}
@test "both collectors still collect when timeout is not on PATH" {
# The documented fallback, which every comparable suite beside this one pins:
# where `timeout` is absent the reads run unbounded rather than not at all, and
# the phase warning promises exactly that by name. `timeout` is a shell function
# in this file, so `command -v timeout` is always true here and the else arm of
# both collectors is otherwise never executed -- a broken redirect or a lost
# `</dev/null` in there would surface only on a runner without coreutils, which
# is the one machine the arm exists for.
tmp=$(mktemp -d)
mkdir -p "$tmp/bin"
for c in sh mkdir date cat grep sed awk rm mv printf; do
for d in /bin /usr/bin /usr/local/bin /opt/homebrew/bin /sbin /usr/sbin; do
if [ -x "$d/$c" ]; then
ln -sf "$d/$c" "$tmp/bin/$c"
break
fi
done
done
for c in sh mkdir date cat grep rm; do
if [ ! -x "$tmp/bin/$c" ]; then
echo "FAIL: could not stage $c in the stripped PATH; the check below would be vacuous" >&2
return 1
fi
done
if [ -e "$tmp/bin/timeout" ]; then
echo "FAIL: timeout leaked into the stripped PATH; this test would prove nothing" >&2
return 1
fi
stage_proc_stat "$tmp/proc-stat"
stage_sandbox_proc "$tmp/proc"
rc=0
# PATH is narrowed INSIDE the subprocess rather than in front of it: the shell
# resolves the command name with the PATH the assignment sets, so a stripped
# PATH in front of `bash` cannot find bash itself. The same trap the KVM suite
# documents beside its own stripped-PATH test.
out=$( ( set +x
bash -c '
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
COZY_REPORT_DIR='"$tmp"'/report
COZY_SNAPSHOT_NAME=runner-cpu-smoke
COZY_DIAG_RUNNER_PROC_STAT='"$tmp"'/proc-stat
COZY_DIAG_SANDBOX_PROC='"$tmp"'/proc
PATH='"$tmp"'/bin
cozy_capture_runner_kernel_cpu_time 1
cozy_capture_sandbox_qemu_thread_cpu 1
' ) 2>&1 ) || rc=$?
[ "$rc" -eq 0 ] || {
echo "FAIL: the collectors ended $rc with no timeout on PATH; the warning promises they keep collecting" >&2
printf '%s\n' "$out" >&2
false
}
assert_file_contains 'cpu 9000000' \
"$tmp/report/snapshots/runner-cpu-smoke/runner-kernel-cpu-time/sample-1/proc-stat.txt"
assert_file_contains 'process 101' \
"$tmp/report/snapshots/runner-cpu-smoke/sandbox-qemu-thread-cpu/sample-1/qemu-threads.txt"
# And each capture says so itself. The phase warning that names unbounded
# collectors fires inside the diagnostics phase, and two of this pair's three
# call sites run outside it, so a capture that ran with no ceiling and stayed
# quiet about it would read exactly like a bounded one.
assert_file_contains '[bounds] timeout is not on PATH here' \
"$tmp/report/snapshots/runner-cpu-smoke/runner-kernel-cpu-time/sample-1/proc-stat.txt"
assert_file_contains '[bounds] timeout is not on PATH here' \
"$tmp/report/snapshots/runner-cpu-smoke/sandbox-qemu-thread-cpu/sample-1/qemu-threads.txt"
rm -rf "$tmp"
}
@test "a pid file that never yields a byte cannot hold the capture" {
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
tmp=$(mktemp -d)
timeout_calls="$tmp/timeout.calls"
stage "$tmp"
# A FIFO with no writer: `[ -r ]` passes on it and the shell redirect open
# would block forever, outside anything a wrapper can cover -- which is why
# the read is an external cat under the read ceiling instead. Staged with a
# low ceiling so the bounded path is what the test exercises; the outer
# timeout is the M20 lesson from the identity suite -- a mutant that removes
# the bound must fail this test, not hang the whole run.
mkdir -p "$tmp/vmroot/srv1" "$tmp/vmroot/srv2"
printf '101\n' >"$tmp/vmroot/srv1/qemu.pid"
mkfifo "$tmp/vmroot/srv2/qemu.pid"
COZY_DIAG_SANDBOX_VM_ROOT="$tmp/vmroot"
COZY_DIAG_READ_TIMEOUT=1
COZY_DIAG_READ_GRACE=1
rc=0
out=$( ( set +x; command timeout 20 bash -c '
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
COZY_REPORT_DIR="'"$tmp"'/report"
COZY_SNAPSHOT_NAME=runner-cpu-smoke
COZY_DIAG_SANDBOX_PROC="'"$tmp"'/proc"
COZY_DIAG_SANDBOX_VM_ROOT="'"$tmp"'/vmroot"
COZY_DIAG_READ_TIMEOUT=1
COZY_DIAG_READ_GRACE=1
cozy_capture_sandbox_qemu_thread_cpu 1
' ) 2>&1 ) || rc=$?
[ "$rc" -eq 0 ] || [ "$rc" -eq 124 ] || {
echo "FAIL: the capture ended $rc; its output follows"
printf '%s\n' "$out"
false
}
[ "$rc" -ne 124 ] || {
echo "FAIL: the capture hung on the FIFO until the outer timeout killed it"
false
}
capture=$(threads_path)
assert_file_contains '[process 101 is srv1]' "$capture"
assert_file_lacks_pattern 'is srv2' "$capture"
assert_file_contains 'had no usable pid file' "$capture"
rm -rf "$tmp"
}