hack/post-install-prep.bats
Rama main · réplica de lectura del repositorio original.
#!/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"
}