Files
cozystack/hack/post-install-prep.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

519 lines
19 KiB
Bash

#!/usr/bin/env bats
# -----------------------------------------------------------------------------
# Unit tests for the wait budgets in hack/e2e-post-install-prep.sh.
#
# The script drives a serial reconcile chain -- cozystack-operator -> platform
# HR -> linstor HR -> piraeus-operator -> cert-manager issues the controller
# TLS -> linstor-controller Deployment -- and every link of it is waited on in
# order. What these tests pin is how the waits are budgeted: each link gets its
# own window measured from the moment the link before it completed, so a long
# but healthy head cannot starve the tail, while a link that never converges
# still fails inside one window rather than running forever.
#
# Strategy: the script is run end to end against a stub PATH carrying a virtual
# clock. `date` reads a counter file, `sleep` advances it, and `kubectl` decides
# each wait from that same counter -- so a 15-minute budget elapses in a few
# hundred forks and the timings are exact rather than wall-clock approximate.
# The stub also records every kubectl invocation, which is how the timeout
# diagnostics are asserted. Mock IPs use the RFC 5737 documentation range.
#
# The convergence times fed in are the ones measured on the two runs that
# motivated this: the linstor HelmRelease went Ready 452s after the script
# started, and the Deployment became Available a further ~520s later.
#
# Title syntax constraints (inherited from cozytest.sh's awk parser):
# - Titles delimited by ASCII double quotes; embedded quotes truncate.
# - Only [A-Za-z0-9] from the title survives into the function name, so keep
# titles distinctive in their alphanumeric run.
# - A line that is exactly `}` is rewritten, so stub bodies below use `case`
# rather than nested functions.
#
# Run with: bats hack/post-install-prep.bats
# -----------------------------------------------------------------------------
load test_helper
HACK_DIR="$(cd "$(dirname "${BATS_TEST_FILENAME:-$0}")" && pwd)"
SCRIPT="$HACK_DIR/e2e-post-install-prep.sh"
# prep_sandbox <dir> -- lay down the stub PATH and the virtual clock.
#
# STUB_HR_READY_AT / STUB_DEPLOY_READY_AT are virtual-clock seconds at which
# the corresponding `kubectl wait` starts succeeding, or the string `never`.
# Every other kubectl call succeeds, so the script's post-LINSTOR tail (storage
# pools, StorageClasses, MetalLB) runs through without a cluster.
prep_sandbox() {
d=$1
mkdir -p "$d/bin"
echo 0 > "$d/clock"
: > "$d/calls"
cat > "$d/bin/date" <<'STUB'
#!/bin/sh
cat "$STUB_CLOCK"
STUB
# Advancing the clock in `sleep` is what makes a 900s budget cost ~180 forks
# instead of 15 minutes. The ceiling is a runaway guard: if the script under
# test loses its deadline check entirely, the wait loop would otherwise spin
# forever, and a hung unit test is worse than a failing one. It has to stay
# low enough to trip in seconds -- a guard that itself takes minutes to fire
# is the hang it was meant to prevent -- and above every budget under test.
# A failing exit status alone does not stop a loop that runs where set -e is
# off, such as a function called under `if !`, so the guard also kills the
# shell that called it.
cat > "$d/bin/sleep" <<'STUB'
#!/bin/sh
now=$(cat "$STUB_CLOCK")
now=$(( now + ${1%%.*} ))
echo "$now" > "$STUB_CLOCK"
if [ "$now" -ge 5000 ]; then
echo "STUB-RUNAWAY: virtual clock passed 5000s" >&2
kill -TERM "$PPID"
exit 1
fi
STUB
# Records the parsed bound and then runs the real command, so a wrapped call
# still reaches the kubectl stub and the existing call assertions hold. The
# duration is parsed here rather than in the test because `timeout [-k G] N`
# puts two numbers on the line and only the second one is the wall clock.
cat > "$d/bin/timeout" <<'STUB'
#!/bin/sh
grace=""
dur=""
while [ $# -gt 0 ]; do
case $1 in
-k) grace=$2; shift 2 ;;
[0-9]*) dur=$1; shift; break ;;
*) break ;;
esac
done
printf 'timeout dur=%s grace=%s -- %s\n' "$dur" "$grace" "$*" >> "$STUB_CALLS"
export STUB_BOUNDED=1
exec "$@"
STUB
cat > "$d/bin/kubectl" <<'STUB'
#!/bin/sh
now=$(cat "$STUB_CLOCK")
printf '%s\n' "$*" >> "$STUB_CALLS"
# A call not run under `timeout`. `kubectl wait --timeout` does not count:
# that timeout starts after the GET that resolves the object, which carries no
# deadline of its own. Recorded on a line of its own so the assertions on the
# plain call lines above keep matching.
bounded=${STUB_BOUNDED:-}
[ -n "$bounded" ] || printf 'UNBOUNDED %s\n' "$*" >> "$STUB_CALLS"
case "$*" in
'wait helmrelease/linstor '*)
# The outer bound firing: `timeout` prints nothing and kubectl dies on the
# signal before it can, so the status is the only trace. 124 on TERM, 137
# when kubectl ignored it and the -k KILL landed.
if [ -n "${STUB_WAIT_KILLED:-}" ]; then exit "$STUB_WAIT_KILLED"; fi
if [ -n "${STUB_WAIT_ERR:-}" ]; then echo "$STUB_WAIT_ERR" >&2; fi
[ "$STUB_HR_READY_AT" != never ] && [ "$now" -ge "$STUB_HR_READY_AT" ] ;;
'wait deployment/linstor-controller '*)
[ "$STUB_DEPLOY_READY_AT" != never ] && [ "$now" -ge "$STUB_DEPLOY_READY_AT" ] ;;
'get endpoints '*) echo 192.0.2.11 ;;
'get crd '*)
if [ -n "${STUB_CRD_MISSING:-}" ]; then
echo 'Error from server (NotFound): customresourcedefinitions.apiextensions.k8s.io "l2advertisements.metallb.io" not found' >&2
exit 1
fi ;;
'get storageprofile local'*)
if [ -n "${STUB_SP_MISSING:-}" ]; then
echo 'Error from server (NotFound): storageprofiles.cdi.kubevirt.io "local" not found' >&2
exit 1
fi ;;
'get hr -n cozy-metallb'*) echo "STUB-METALLB-HR metallb False install retries exhausted" ;;
'get hr -A '*)
echo "cozy-linstor linstor False dependency 'cozy-system/piraeus-operator' is not ready"
echo "STUB-HR cozy-kubeovn kubeovn False install retries exhausted" ;;
'get pods '*)
if [ -n "${STUB_PODS_FAIL:-}" ]; then
echo "Error from server (Forbidden): pods is forbidden" >&2
exit 1
fi
echo "STUB-POD linstor-controller 0/1 Init:CrashLoopBackOff" ;;
'events '*|'get events '*)
# Model the failure the real sorter has: an Event written through
# events.k8s.io/v1 reaches the core API with .lastTimestamp unset, and
# kubectl fails the whole read rather than skipping that item. A
# diagnostic that dies this way prints nothing, which reads exactly like
# a namespace with no events -- so the assertion below is on the content
# arriving, not on the call being made.
case "$*" in
*--sort-by=.lastTimestamp*)
echo "error: couldn't find any field with path {.lastTimestamp}" >&2
exit 1 ;;
esac
# Any other reason the read can fail -- RBAC, a wedged apiserver, a
# renamed namespace. Kept separate from the sort-key case above so the
# cause and the consequence are pinned by different tests.
if [ -n "${STUB_EVENTS_FAIL:-}" ]; then
echo "Error from server (Forbidden): events is forbidden" >&2
exit 1
fi
echo "STUB-EVENT MountVolume.SetUp failed for volume client-tls" ;;
*'linstor sp l '*)
# What the outer bound firing looks like from here: `timeout` prints
# nothing and kubectl dies on the signal before it can, so the only
# trace is the status.
if [ -n "${STUB_SPL_KILLED:-}" ]; then
exit 124
fi
# A remote command killed inside the container, OOM for one: kubectl
# exec hands its status back, and 137 is also what `timeout -k` returns.
if [ -n "${STUB_SPL_REMOTE_KILLED:-}" ]; then
echo 'command terminated with exit code 137' >&2
exit 137
fi ;;
*'linstor node list')
i=0
while [ "$i" -lt "${STUB_ONLINE:-3}" ]; do echo Online; i=$((i + 1)); done ;;
*) exit 0 ;;
esac
STUB
chmod +x "$d/bin/date" "$d/bin/sleep" "$d/bin/kubectl" "$d/bin/timeout"
}
# run_prep <dir> <hr-ready-at> <deploy-ready-at> [events-fail] [pods-fail]
# Runs the script under the stubs, capturing stdout, stderr and the exit status
# without tripping set -e. The last two are non-empty to make the corresponding
# diagnostic read fail; pass an empty string for the fourth to reach the fifth.
run_prep() {
d=$1
STUB_CLOCK="$d/clock" STUB_CALLS="$d/calls" \
STUB_HR_READY_AT=$2 STUB_DEPLOY_READY_AT=$3 \
STUB_EVENTS_FAIL="${4:-}" STUB_PODS_FAIL="${5:-}" \
PATH="$d/bin:$PATH" \
"$SCRIPT" > "$d/out" 2> "$d/err" && echo 0 > "$d/rc" || echo $? > "$d/rc"
}
@test "the Deployment wait keeps its full budget after a slow HelmRelease wait" {
tmp=$(mktemp -d)
prep_sandbox "$tmp"
run_prep "$tmp" 452 972
cat "$tmp/err" >&2
[ "$(cat "$tmp/rc")" -eq 0 ]
grep -q '\[post-install-prep\] done' "$tmp/out"
# The Deployment converged past the point where a single chain-wide 15m
# window anchored at script start would already have expired.
[ "$(cat "$tmp/clock")" -ge 972 ]
rm -rf "$tmp"
}
@test "a Deployment that never becomes Available fails inside one budget" {
tmp=$(mktemp -d)
prep_sandbox "$tmp"
run_prep "$tmp" 0 never
[ "$(cat "$tmp/rc")" -ne 0 ]
# One budget, not two and not unbounded: the wait started at 0 and gave up
# at 900. The upper bound allows a single 5s poll interval beyond that and
# nothing more, so a second budget would fail it.
final=$(cat "$tmp/clock")
[ "$final" -ge 900 ]
[ "$final" -le 905 ]
rm -rf "$tmp"
}
@test "the Deployment timeout reports the linstor pods and events" {
tmp=$(mktemp -d)
prep_sandbox "$tmp"
run_prep "$tmp" 0 never
[ "$(cat "$tmp/rc")" -ne 0 ]
grep -q 'timed out' "$tmp/err"
grep -q 'linstor-controller Deployment to be Available' "$tmp/err"
# Which link was actually blocking -- a crash-looping init container versus a
# Secret cert-manager has not issued yet -- is only visible in the pods and
# the namespace events, so the timeout has to read both.
grep -q '^get pods -n cozy-linstor' "$tmp/calls"
grep -q '^events -n cozy-linstor' "$tmp/calls"
# And their content has to reach the log, not merely be asked for: a read
# that fails prints nothing, which is the same shape as a namespace with
# nothing wrong in it.
grep -q 'STUB-POD' "$tmp/err"
grep -q 'STUB-EVENT' "$tmp/err"
# Both reads carry a wall-clock bound, and the client budget inside each is
# strictly smaller than it. Equal values would put the outer kill first, so
# kubectl would never get to say why it could not read -- which is the whole
# point of reading at all on this path.
for what in 'get pods' 'events'; do
line=$(grep "^timeout dur=.* kubectl $what -n cozy-linstor" "$tmp/calls" | head -1)
[ -n "$line" ]
outer=${line#timeout dur=}
outer=${outer%% *}
inner=$(printf '%s' "$line" | sed -n 's/.*--request-timeout=\([0-9]*\)s.*/\1/p')
[ -n "$outer" ]
[ -n "$inner" ]
[ "$inner" -lt "$outer" ]
done
rm -rf "$tmp"
}
@test "an events read that fails names its reason instead of going quiet" {
tmp=$(mktemp -d)
prep_sandbox "$tmp"
run_prep "$tmp" 0 never fail-events
[ "$(cat "$tmp/rc")" -ne 0 ]
# Silence here would be read as "the namespace had nothing to say", which is
# the opposite of what happened. The reason has to survive to the log.
grep -q 'Forbidden' "$tmp/err"
rm -rf "$tmp"
}
@test "a leg that fails does not take the other leg down with it" {
tmp=$(mktemp -d)
prep_sandbox "$tmp"
# The pods read runs first, so failing it is the only way to ask whether the
# events read still happens. Failing the events read instead proves nothing:
# the pods output has already been emitted by then either way.
run_prep "$tmp" 0 never '' fail-pods
[ "$(cat "$tmp/rc")" -ne 0 ]
grep -q 'Forbidden' "$tmp/err"
grep -q 'STUB-EVENT' "$tmp/err"
rm -rf "$tmp"
}
@test "a HelmRelease that never goes Ready fails before the Deployment is waited on" {
tmp=$(mktemp -d)
prep_sandbox "$tmp"
run_prep "$tmp" never 0
[ "$(cat "$tmp/rc")" -ne 0 ]
grep -q 'linstor HelmRelease to be Ready' "$tmp/err"
final=$(cat "$tmp/clock")
[ "$final" -ge 900 ]
[ "$final" -le 905 ]
if grep -q '^wait deployment/linstor-controller' "$tmp/calls"; then
echo "the Deployment was waited on after the HelmRelease wait failed" >&2
return 1
fi
rm -rf "$tmp"
}
@test "every kubectl call on the success, container and every timeout path carries a bound" {
# The caller blocks in `wait` on this script, so a single call that never
# returns holds the install open until the job's own ceiling instead of
# failing a step. A deadline checked between iterations does not help: the
# check sits on the other side of the call that hangs. The timeout paths
# matter most: their reads run only once the cluster is already unhealthy.
for path in success container node-timeout hr-timeout metallb-timeout sp-timeout; do
tmp=$(mktemp -d)
prep_sandbox "$tmp"
hr_ready=0
case $path in
node-timeout) export STUB_ONLINE=2 ;;
# The only path that patches the CDI StorageProfile.
container) export COZY_LINSTOR_DRBD_ENABLED=false ;;
hr-timeout) hr_ready=never ;;
metallb-timeout) export STUB_CRD_MISSING=1 ;;
sp-timeout) export COZY_LINSTOR_DRBD_ENABLED=false STUB_SP_MISSING=1 ;;
esac
run_prep "$tmp" "$hr_ready" 0
unset STUB_ONLINE COZY_LINSTOR_DRBD_ENABLED STUB_CRD_MISSING STUB_SP_MISSING
case $path in
success|container) [ "$(cat "$tmp/rc")" -eq 0 ] ;;
*)
[ "$(cat "$tmp/rc")" -ne 0 ]
grep -q 'timed out' "$tmp/err" ;;
esac
if grep '^UNBOUNDED ' "$tmp/calls" >&2; then
echo "unbounded kubectl calls on the $path path" >&2
return 1
fi
# A plain request keeps a client budget strictly inside the wall clock one,
# so kubectl names why it could not finish before the kill lands.
grep '^timeout dur=.* -- kubectl \(get\|apply\|patch\|events\) ' "$tmp/calls" > "$tmp/reads" || true
[ -s "$tmp/reads" ]
while IFS= read -r line; do
outer=${line#timeout dur=}
outer=${outer%% *}
inner=$(printf '%s' "$line" | sed -n 's/.*--request-timeout=\([0-9]*\)s.*/\1/p')
if [ -z "$inner" ] || [ "$inner" -ge "$outer" ]; then
echo "client budget not inside the wall clock one: $line" >&2
return 1
fi
done < "$tmp/reads"
rm -rf "$tmp"
done
}
@test "a client error in the wait loop reaches the log instead of a bare timeout" {
tmp=$(mktemp -d)
prep_sandbox "$tmp"
# Exits non-zero at once, like NotFound, so by status alone the loop cannot
# tell it from an object that is not created yet. Without the text the
# timeout names the HelmRelease while the cause sits in the client.
export STUB_WAIT_ERR='error: You must be logged in to the server (Unauthorized)'
run_prep "$tmp" never 0
unset STUB_WAIT_ERR
[ "$(cat "$tmp/rc")" -ne 0 ]
grep -q 'linstor HelmRelease to be Ready' "$tmp/err"
grep -q 'Unauthorized' "$tmp/err"
rm -rf "$tmp"
}
@test "a NotFound repeated on every attempt is printed once, not every poll" {
tmp=$(mktemp -d)
prep_sandbox "$tmp"
export STUB_WAIT_ERR='Error from server (NotFound): helmreleases.helm.toolkit.fluxcd.io "linstor" not found'
run_prep "$tmp" never 0
unset STUB_WAIT_ERR
[ "$(cat "$tmp/rc")" -ne 0 ]
# The timeout line repeats the last error; outside it, one line in ~180
# attempts. Printing every attempt would bury the rest of the log.
n=$(grep -v 'timed out' "$tmp/err" | grep -c 'not found' || true)
[ "$n" -eq 1 ]
grep 'timed out' "$tmp/err" | grep -q 'not found'
# Printed on every green run too, since the release appears ~70s in, so it
# has to read as this script's progress rather than as a failure.
grep -v 'timed out' "$tmp/err" | grep 'not found' | grep -q '^\[post-install-prep\] '
rm -rf "$tmp"
}
@test "a wait attempt cut by its outer bound says so in the timeout line" {
for code in 124 137; do
tmp=$(mktemp -d)
prep_sandbox "$tmp"
export STUB_WAIT_KILLED=$code
run_prep "$tmp" never 0
unset STUB_WAIT_KILLED
[ "$(cat "$tmp/rc")" -ne 0 ]
# Without this the line reads "last kubectl error: none", which says the
# client had nothing to report, not that it was killed mid-request.
grep 'timed out' "$tmp/err" | grep -q 'cut by its outer bound'
rm -rf "$tmp"
done
}
@test "a linstor HelmRelease timeout names the upstream release that blocks it" {
tmp=$(mktemp -d)
prep_sandbox "$tmp"
run_prep "$tmp" never 0
[ "$(cat "$tmp/rc")" -ne 0 ]
grep -q 'linstor HelmRelease to be Ready' "$tmp/err"
# The linstor release is usually the victim of a dependency chain, not the
# cause, and the cozy-linstor pods say nothing about kubeovn. The release
# list carries every Ready message, so the blocking release is named in the
# same log that reports the timeout.
grep -q 'STUB-HR cozy-kubeovn kubeovn' "$tmp/err"
rm -rf "$tmp"
}
@test "a MetalLB CRD wait that runs out says so and shows which CRD is missing" {
tmp=$(mktemp -d)
prep_sandbox "$tmp"
export STUB_CRD_MISSING=1
run_prep "$tmp" 0 0
unset STUB_CRD_MISSING
[ "$(cat "$tmp/rc")" -ne 0 ]
# A silent exit here leaves the "waiting for" line as the last word, which
# cannot tell CRDs that are late from an operator that never got that far.
grep -q 'timed out after 300s waiting for MetalLB CRDs' "$tmp/err"
grep -q 'l2advertisements.metallb.io" not found' "$tmp/err"
grep -q 'STUB-METALLB-HR' "$tmp/err"
final=$(cat "$tmp/clock")
[ "$final" -ge 300 ]
[ "$final" -le 302 ]
rm -rf "$tmp"
}
@test "a CDI StorageProfile wait that runs out says so before any patch" {
tmp=$(mktemp -d)
prep_sandbox "$tmp"
export COZY_LINSTOR_DRBD_ENABLED=false STUB_SP_MISSING=1
run_prep "$tmp" 0 0
unset COZY_LINSTOR_DRBD_ENABLED STUB_SP_MISSING
[ "$(cat "$tmp/rc")" -ne 0 ]
grep -q 'timed out after 600s waiting for CDI StorageProfile/local' "$tmp/err"
grep -q 'storageprofiles.cdi.kubevirt.io "local" not found' "$tmp/err"
if grep -q '^patch storageprofile' "$tmp/calls"; then
echo "the StorageProfile was patched although it never appeared" >&2
return 1
fi
rm -rf "$tmp"
}
@test "container mode waits for the CDI StorageProfile before patching it" {
tmp=$(mktemp -d)
prep_sandbox "$tmp"
export COZY_LINSTOR_DRBD_ENABLED=false
run_prep "$tmp" 0 0
unset COZY_LINSTOR_DRBD_ENABLED
[ "$(cat "$tmp/rc")" -eq 0 ]
# CDI creates the profile asynchronously; a patch sent first fails on a
# profile that does not exist yet.
got=$(grep -n '^get storageprofile local' "$tmp/calls" | head -1 | cut -d: -f1)
patched=$(grep -n '^patch storageprofile local' "$tmp/calls" | head -1 | cut -d: -f1)
[ -n "$got" ]
[ -n "$patched" ]
[ "$got" -lt "$patched" ]
rm -rf "$tmp"
}
@test "a storage pool listing killed by its bound stops before any pool is created and says so" {
tmp=$(mktemp -d)
prep_sandbox "$tmp"
# Read as "no pools exist", a failed listing sends a create for every node,
# and the ones that do exist fail it with a reason that is not the cause.
export STUB_SPL_KILLED=1
run_prep "$tmp" 0 0
unset STUB_SPL_KILLED
[ "$(cat "$tmp/rc")" -ne 0 ]
# Nothing else in the log would say why the script stopped.
grep 'killed after 300s' "$tmp/err" | grep -q 'linstor sp l'
if grep -q 'create-device-pool' "$tmp/calls"; then
echo "pools were created after the listing failed" >&2
return 1
fi
rm -rf "$tmp"
}
@test "a listing whose remote command was killed is not reported as the bound firing" {
tmp=$(mktemp -d)
prep_sandbox "$tmp"
export STUB_SPL_REMOTE_KILLED=1
run_prep "$tmp" 0 0
unset STUB_SPL_REMOTE_KILLED
[ "$(cat "$tmp/rc")" -ne 0 ]
grep -q 'command terminated with exit code 137' "$tmp/err"
if grep -q 'killed after' "$tmp/err"; then
echo "a remote kill was blamed on the call bound" >&2
return 1
fi
rm -rf "$tmp"
}