#!/bin/sh ############################################################################### # cozytest.sh - Bats-compatible test runner with live trace and enhanced # # output, written in pure shell # ############################################################################### set -eu TEST_FILE=${1:?Usage: ./cozytest.sh [pattern]} PATTERN=${2:-*} LINE='----------------------------------------------------------------' # Live per-line streaming of each test's xtrace and command output, prefixed # with a timestamp. Default on, because for a long e2e suite that stream is the # only progress signal, and the only record at all when a step timeout or a dead # runner kills the job before the fail handler below can dump anything. # # Set COZYTEST_TRACE=0 to keep only the per-test start/end lines. For a test that # RETURNS, nothing diagnostic is lost: run_one tees the raw stream to $log and # the fail handler prints all of it, so quiet mode drops the output of passing # tests only -- which by definition did not establish the result. On the unit # lane that is a ~40x cut (1338 tests: 239k lines/15M of which 98% was trace), # and it is why the Makefile's bats-posix-compat-tests target sets it. # # One exception, stated because it is the whole exposure quiet mode adds: the # fail handler runs only after the pipeline returns, and there is no INT/TERM # trap here, so a test killed rather than failed -- a hang reaped by the job's # timeout-minutes, a SIGKILLed process group -- never dumps $log at all. The # A start line with no matching end still names which test was in flight, but # under quiet mode its trace is gone rather than already printed. # # An INT/TERM trap that flushed the tail of $log is the obvious repair and it # does not work -- built, measured, reverted. POSIX sh defers a trap until the # current foreground command returns, so installing one stops the runner from # dying on the signal at all: a suite hung on `sleep 30` took 30s to exit with # the trap versus 2s under the default disposition. GitHub's cancellation # escalates INT, TERM, then KILL, so the deferred handler would be SIGKILLed # before it ever ran -- no dump, and the grace period spent waiting. Making it # work means running the test pipeline in the background and `wait`ing on it, # since `wait` is the interruptible one; that is surgery on the path every # suite in the repo takes, for a partial trace in a rare case. # # So the escape hatch stands instead: re-run that suite with COZYTEST_TRACE=1, # which for the unit lane costs 48s and needs no cluster. That asymmetry is # also why e2e keeps the stream on by default -- there, re-running is an hour # and a live cluster, so the record has to be written as it goes. # # Anything other than the literal 0 leaves the stream on, so a typo fails # open to the verbose behaviour rather than silently swallowing a suite. COZYTEST_TRACE=${COZYTEST_TRACE:-1} cols() { stty size 2>/dev/null | awk '{print $2}' || echo 80; } if [ -t 1 ]; then MAXW=$(( $(cols) - 12 )); [ "$MAXW" -lt 40 ] && MAXW=70 else MAXW=0 # no truncation when not a tty (e.g. CI) fi BEGIN=$(date +%s) timestamp() { s=$(( $(date +%s) - BEGIN )); printf '[%02d:%02d]' $((s/60)) $((s%60)); } ############################################################################### # run_one # ############################################################################### run_one() { fn=$1 title=$2 tmp=$(mktemp -d) || { echo "Failed to create temp directory" >&2; exit 1; } log="$tmp/log" echo "╭ » Run test: $title" START=$(date +%s) skip_next="+ $fn" { ( PS4='+ ' # prefix for set -x set -eu -x # strict + trace "$fn" ) printf '__RC__%s\n' "$?" } 2>&1 | tee "$log" | while IFS= read -r line; do if [ "$COZYTEST_TRACE" = 0 ]; then continue; fi case "$line" in '__RC__'*) : ;; '+ '*) cmd=${line#'+ '} [ "$cmd" = "${skip_next#+ }" ] && continue case "$cmd" in 'set -e'|'set -x'|'set -u'|'return 0') continue ;; esac out=$cmd ;; *) out=$line ;; esac now=$(( $(date +%s) - START )) [ "$MAXW" -gt 0 ] && [ ${#out} -gt "$MAXW" ] && out="$(printf '%.*s…' "$MAXW" "$out")" printf '┊[%02d:%02d] %s\n' $((now/60)) $((now%60)) "$out" done # LC_ALL=C so BSD awk scans the captured log byte-wise: a test whose trace or # output carries a multibyte character would otherwise abort this scan ("towc: # multibyte conversion failure") and leave the exit code unread. rc=$(LC_ALL=C awk '/^__RC__/ {print substr($0,7)}' "$log" | tail -n1) [ -z "$rc" ] && rc=1 now=$(( $(date +%s) - START )) if [ "$rc" -eq 0 ]; then printf '╰[%02d:%02d] ✅ Test OK: %s\n' $((now/60)) $((now%60)) "$title" else printf '╰[%02d:%02d] ❌ Test failed: %s (exit %s)\n' \ $((now/60)) $((now%60)) "$title" "$rc" echo "----- captured output -----------------------------------------" grep -v '^__RC__' "$log" echo "$LINE" rm -rf "$tmp" exit "$rc" fi rm -rf "$tmp" } ############################################################################### # convert .bats -> shell-functions # ############################################################################### TMP_SH=$(mktemp) || { echo "Failed to create temp file" >&2; exit 1; } # Per-file lifecycle hook. cozytest.sh runs each .bats as a single invocation # and exit()s on the first failing @test, so this EXIT trap is the one place to: # 1. on failure, snapshot the HOST cluster with crust-gather BEFORE any cleanup, # so each failed test keeps its own inspectable state instead of one # end-of-suite dump; # 2. ALWAYS run the file's cozy_cleanup() if it defines one, so a test never # leaks resources into the shared tenant-test namespace (left-behind PVCs # otherwise exhaust the tenant quota and cascade-fail every later app). # cozy_cleanup is a plain shell function a .bats file may define — there are no # bats setup/teardown directives here, this runner only knows @test + bash. # NOTE: nested tenant clusters are NOT captured here. This trap runs in the # parent shell after the failing test subshell has exited and reaped its # port-forward, and crust-gather can only reach a tenant via that localhost # forward — so a test that creates tenant clusters (run-kubernetes.sh) captures # them from its OWN in-subshell EXIT trap, while the forward is still alive. COZY_REPORT_DIR="${COZY_REPORT_DIR:-_out/cozyreport}" # Which suites get the cluster captures below. They read cluster state, so they # belong to the e2e suites and to nothing else. `command -v kubectl` does not # tell the two apart: a unit runner has the binary and no cluster, so a red unit # test used to walk into the legs below on its way out. # # What that costs depends on how kubectl fails. Against an endpoint that refuses # immediately it is a second; against one that hangs -- an unreachable address, a # context left pointing at a torn-down cluster -- it was measured at ~28s for the # previous-logs leg, which self-bounds its pod list and so never reaches the 300s # ceiling set below it. The data-plane leg bounds its own reads as well, 28s for # a list and 20s for a single read, so it returns in tens of seconds rather than # holding its 600s ceiling. Dead waiting inside a job budget either way, for a # failure that should cost seconds. # # Where crust-gather is installed as well the bill stops being empty and starts # being wrong: that leg does not need a reachable cluster to be pointless, it # needs an ambient KUBECONFIG, and it can hold the trap for 390s -- its 360s # deadline plus the -k 30 kill grace -- snapshotting whatever cluster the # current context happens to name. # # The discriminator is the e2e- prefix, on the suite's own name or on the # directory holding it. At the top level the prefix is what the project already # sorts on: the Makefile builds BATS_UNIT_FILES as # $(filter-out hack/e2e-%.bats,$(wildcard hack/*.bats)), so a top-level e2e-* # suite is precisely one `make unit-tests` refuses to run and # packages/core/testing/Makefile runs against a live cluster instead. # # That wildcard is not recursive, so it says nothing about subdirectories, and # hack/e2e-apps/ historically held live-cluster suites whose own filenames # carried no prefix. Keep matching the directory so captures stay armed if that # layout returns; matching only the basename would silently disarm them. Neither # test claims every future live-cluster suite will be named this way -- these are # the only signals the runner has, and a suite outside both shapes gets no # captures. # # Deliberately not a reachability probe. Gating on "can I talk to an apiserver" # would disarm the captures in the case they exist for: a failing e2e run is # often one whose apiserver is degraded, and a probe answering "no" there would # skip the snapshot precisely when it is the evidence. case "$(basename "$TEST_FILE")" in e2e-*) _cozy_cluster_captures=1 ;; *) case "$(basename "$(dirname "$TEST_FILE")")" in e2e-*) _cozy_cluster_captures=1 ;; *) _cozy_cluster_captures=0 ;; esac ;; esac _cozy_on_exit() { _rc=$? if [ "$_rc" -ne 0 ]; then _snap="$COZY_REPORT_DIR/snapshots/$(basename "$TEST_FILE" .bats)" mkdir -p "$_snap" 2>/dev/null || true # Previous-instance container logs for anything that crash-looped. `kubectl # logs` shows only the current instance, so for a crash-looping pod the # decisive evidence — the immediately preceding run — is reachable only via # `--previous` and is lost once the kubelet garbage-collects that container. # FIRST, ahead of both captures below: it is the cheapest leg and the only # one whose subject is perishable. The kubelet retains one dead container # per pod by default, so each further restart of a still-looping pod drops # the instance we are here to read — and the snapshot leg alone can hold the # trap for 390s. The other two captures read state that keeps. if [ "$_cozy_cluster_captures" -eq 1 ] && command -v kubectl >/dev/null 2>&1 && [ -x "$(dirname "$0")/e2e-capture-previous-logs.sh" ]; then _prev_rc=0 timeout -k 30 300 "$(dirname "$0")/e2e-capture-previous-logs.sh" \ "$_snap/previous-logs" "${COZY_TEST_NAMESPACE:-tenant-test}" 2>&1 || _prev_rc=$? # A backstop that fires must say so, matching the crust-gather leg below. # 300s sits above the ~270s worst case inside (a ~30s pod list plus up to # 12 × 20s log reads), so it should not fire; if it does, a silently cut # capture would read as a complete one listing fewer crash-loops than # actually occurred. This handler's whole worst case is ~1350s (330 + 390 # + 630, each leg including its 30s kill grace) against a job capped at # 215 minutes with no per-step timeout — # deliberate, for the same reason recorded in hack/e2e-chainsaw/.chainsaw.yaml: # a bounded, honest wait beats a kill that collects nothing. if [ "$_prev_rc" -ne 0 ]; then echo "» previous-instance capture INCOMPLETE (exit $_prev_rc); kept what landed in $_snap/previous-logs" fi fi if [ "$_cozy_cluster_captures" -eq 1 ] && command -v crust-gather >/dev/null 2>&1; then echo "» capturing crust-gather snapshot of failed $(basename "$TEST_FILE") -> $_snap" # Bound with a timeout: crust-gather collect has hung indefinitely on a # contended/degraded cluster (e.g. streaming logs from a crashlooping pod), # wedging the whole test step for hours until the job-level cancel. 5 min is # ample for a host snapshot; a partial capture (timeout exits 124, swallowed # by `|| true`) still beats a multi-hour hang. -k 30 hard-kills if a blocked # collect ignores the SIGTERM. # --duration is crust-gather's own budget for the collection phase and # defaults to 60s, which silently truncates a snapshot of a cluster this # size: on elapse it abandons the collection and skips its finish step, # leaving a partial tree with no indication that the rest is missing. Set # it explicitly. The outer wall-clock must exceed it because crust-gather # runs API discovery BEFORE that timer starts and that phase is unbounded # — with an unhealthy aggregated APIService (the state a failed run is # usually in) discovery alone can eat the whole budget before a single # object is written. # Output goes to a log inside the snapshot instead of /dev/null so # "is this snapshot complete or truncated?" is answerable from the # uploaded artifact rather than guessed, matching the Chainsaw catch. _cg_rc=0 # --disable-additional-logs: the host-log leg spawns a privileged debug pod per # node, which baseline PodSecurity rejects (403); its retry loop then burns the # whole --duration and crust-gather exits 1. Skip it — it collects nothing here. timeout -k 30 360 crust-gather collect --disable-additional-logs --duration 180s \ --exclude-kind Secret -f "$_snap/host" >"$_snap/crust-gather.log" 2>&1 || _cg_rc=$? case "$_cg_rc" in 0) echo "» crust-gather host snapshot complete" ;; 124 | 137) echo "» crust-gather host snapshot TRUNCATED (wall-clock $_cg_rc); partial state kept, see $_snap/crust-gather.log" ;; *) echo "» crust-gather host snapshot FAILED (exit $_cg_rc); see $_snap/crust-gather.log" ;; esac fi # Diagnostic-only: capture the host->pod CNI data-plane state for any # NotReady pod so the recurrent host->local-pod "connection refused" # transient (rooted in our cilium+kube-ovn chaining: # enable-host-legacy-routing + CNI InstallEndpointRoute:false, which # delegates host->local-pod routing to kube-ovn/ovn0) can be root-caused # from the uploaded artifact. crust-gather captures object state but not the # node's L3 forwarding state. This NEVER affects the test outcome: every # capture inside is time-boxed and `|| true`, the whole run is wrapped in a # wall-clock backstop so it cannot stall the job, and the backstop's own # status is read only to print a line. It no-ops when there are no affected # pods or when kubectl/the tooling is absent. # The `-x` check matches the previous-logs leg above and the Chainsaw # caller, and it stopped being cosmetic once the status below is printed: a # tree without the collector would otherwise report "INCOMPLETE (exit 127); # kept what landed" about a directory nothing ever created. if [ "$_cozy_cluster_captures" -eq 1 ] && command -v kubectl >/dev/null 2>&1 && [ -x "$(dirname "$0")/e2e-capture-dataplane.sh" ]; then echo "» capturing host->pod data-plane for NotReady pods -> $_snap/dataplane" _dp_rc=0 COZY_DATAPLANE_BUDGET=570 timeout -k 30 600 "$(dirname "$0")/e2e-capture-dataplane.sh" "$_snap/dataplane" 2>&1 || _dp_rc=$? # Read, not propagated: the status still cannot change the job's outcome, # it only gets a line. The collector names every read of its own that it # could not finish, which leaves this backstop as the one remaining way # for that leg to die silently -- and a truncated dataplane/ is otherwise # indistinguishable from a complete one that found little. Same discipline # as the previous-logs leg above, whose comment carries the arithmetic. if [ "$_dp_rc" -ne 0 ]; then echo "» data-plane capture INCOMPLETE (exit $_dp_rc); kept what landed in $_snap/dataplane" fi fi fi if command -v cozy_cleanup >/dev/null 2>&1; then echo "» cozy_cleanup $(basename "$TEST_FILE" .bats)" cozy_cleanup || true fi rm -f "$TMP_SH" } trap '_cozy_on_exit' EXIT # LC_ALL=C pins a single-byte ctype for the title scan below. It walks each title # one character at a time with substr(), and BSD awk aborts that walk on the first # multibyte byte ("towc: multibyte conversion failure") instead of returning it, # so a file with a non-ASCII @test title never parses and none of its tests run. # Under C every byte is its own character, which is all the scan needs: the title # is preserved verbatim for display and only the derived function name is mangled. # The run-selection pass below is pinned the same way so the two agree on names. LC_ALL=C awk ' /^@test[[:space:]]+"/ { line = substr($0, index($0, "\"") + 1) title = substr(line, 1, index(line, "\"") - 1) fname = "test_" for (i = 1; i <= length(title); i++) { c = substr(title, i, 1) fname = fname (c ~ /[A-Za-z0-9]/ ? c : "_") } printf("### %s\n", title) printf("%s() {\n", fname) print " set -e" next } /^}$/ { print " return 0" print "}" next } { print } ' "$TEST_FILE" > "$TMP_SH" [ -f "$TMP_SH" ] || { echo "Failed to generate test functions" >&2; exit 1; } # Compatibility with unit files shared with Bats. Only adjacent .bash helpers # are supported; cozytest already enables nounset when it runs a test body. load() { _lib="$(dirname "$TEST_FILE")/$1.bash" [ -f "$_lib" ] || { echo "load: no such helper: $_lib" >&2; return 1; } # shellcheck disable=SC1090 . "$_lib" } # shellcheck disable=SC1090 . "$TMP_SH" ############################################################################### # run selected tests # ############################################################################### LC_ALL=C awk -v pat="$PATTERN" ' /^### / { title = substr($0, 5) name = "test_" for (i = 1; i <= length(title); i++) { c = substr(title, i, 1) name = name (c ~ /[A-Za-z0-9]/ ? c : "_") } if (pat == "*" || index(title, pat) > 0) printf("%s %s\n", name, title) } ' "$TMP_SH" | while IFS=' ' read -r fn title; do run_one "$fn" "$title" done