mirror of
https://github.com/cozystack/cozystack.git
synced 2026-11-09 22:13:18 +09:00
test(e2e): time the guest console capture and baseline it on a green run (#3841)
## What this PR does A tenant worker's guest serial console is stamped in seconds since that guest's own kernel started. So a log that ends mid-boot tells you how far the guest got and nothing at all about when that was. Whether it ends there because the guest started late or because the guest stopped printing is the difference between two unrelated failures, and neither instant was written down anywhere: the read's own instant was nowhere in the file, surviving only as the artifact's mtime, which is metadata rather than content and so says nothing to anyone who opens the log, and the guest's start only inside a `describe` dump that the capture triggers exclusively when some console came back silent. On a run where every console returned bytes, that dump does not exist. I went looking for the answer in three collected reports before changing anything. Every one of the twelve captures across them exited zero, so no read was truncated by its 30s bound or by `--limit-bytes`, and the logs are 23 to 79 KB against a 1 MiB cap. The captures stop at 305, 370, 432, 456, 474, 497, 564, 570, 583, 599 and 639 guest seconds. A fixed cutting mechanism does not produce a 334 second spread. The logs end where the guests stopped printing. On the single worker where both ends were recoverable at all, by reading the file's mtime and the describe together, the guest had been alive for 955 seconds and had printed up to second 564. Each console log now carries the instant its own read started and returned, and `CAPTURE-TIMELINE.txt` beside it carries each Pod's phase, its start time and the start of its compute and console containers, from one bounded read taken once for the whole selector rather than per Pod. Those two subtract to how long a guest had been alive when it was read, which is what the log's last kernel stamp gets compared against. Close together means the guest was still printing and the log ends because it had not got further. Far apart means it stopped. A Pod with no compute start never ran a guest at all, whatever its console file says. The legend in the file names the units on both ends, because an epoch integer and an RFC 3339 string subtract to nonsense if you take them as printed. A read that failed and a read that answered with nothing are written down as themselves instead of leaving an absent file. The same capture now also runs on the passing path, after the last assertion and before the tenant is deleted, because the container holding the stream goes with the Pod and no read recovers it afterwards. Every console this tree has collected came from a failure, so nobody has ever measured what a healthy boot looks like, while "slower than usual" is the claim the node-join failure keeps resting on. That caller asks for the pool's minimum rather than its maximum, since two workers booting is the same measurement as ten, and it warns in the job log instead of failing a suite that has already proved everything it exists to prove. Both paths write the same directory, so the capture records which of them produced it. The cost moves by one bounded read. The serial console family goes from roughly 5m50s to 6m25s at worst and from 3m30s to 4m05s at the pool minimum, both against the 7m diagnostics phase budget, and the figure in both suite comments moves with it under the guard that holds the two in step. The passing path adds six bounded reads at 30s and 5s kill grace, so 210s. That 210s is real wall clock at the tail of an operation with a fixed 50m ceiling, which is a way for a run that already passed to be killed while collecting a debugging aid. So the passing-path capture declines itself out loud when the ceiling no longer has room for it, against a reserve derived from its own cost plus the deletes after it. The ceiling it measures against is read from both sides by a guard, so a suite that changes its `timeout:` fails there rather than leaving the reserve protecting a number that moved. What this deliberately does not do is widen a capture window. I could not derive a number for one that would be honest. The reads are already complete, so there is no read side bound to relax, and the only remaining lever is waiting longer before reading. How much longer depends on whether the tail silence is the guest freezing or the stream stopping, and that is precisely what was not measurable. The evidence leans toward the guest: the logs end on complete lines, and one of them ends on an RCU stall backtrace, which is the kernel reporting it was not being scheduled. If that holds, the silence has no ceiling and no fixed window can promise to contain a milestone. The green baseline this adds is what would set the number, and it does not exist yet. Context for cozystack/cozystack#3513, which this does not fix. It restores the instrument that investigation needs. ### Screenshots Not a UI change. ### Downstream repositories I walked the trigger map in `docs/agents/contributing.md` against the actual diff. It touches `docs/agents/e2e-testing.md`, the shared e2e helper `hack/e2e-chainsaw/_lib/run-kubernetes.sh`, the two `kubernetes-*` suite files and three unit test files under `hack/`. Nothing under `packages/`, no `ApplicationDefinition`, no values schema or enum or default, no namespace, no emitted metric, no label or annotation another component reads, no node prerequisite in `hack/e2e-prepare-cluster.bats`, no make target and no file moved or renamed under `hack/`. No trigger in the map matches. - [x] No downstream repository is affected by this change - [ ] [cozystack/website](https://github.com/cozystack/website) - follow-up: - [ ] [cozystack/terraform-provider-cozystack](https://github.com/cozystack/terraform-provider-cozystack) - follow-up: - [ ] [cozystack/ansible-cozystack](https://github.com/cozystack/ansible-cozystack) - follow-up: - [ ] [cozystack/ccp](https://github.com/cozystack/ccp) - follow-up: - [ ] [cozystack/talm](https://github.com/cozystack/talm) - follow-up: - [ ] [cozystack/cozyhr](https://github.com/cozystack/cozyhr) - follow-up: - [ ] [cozystack/cozy-proxy](https://github.com/cozystack/cozy-proxy) - follow-up: - [ ] [cozystack/cozystack-telemetry-server](https://github.com/cozystack/cozystack-telemetry-server) - follow-up: - [ ] [cozystack/external-apps-example](https://github.com/cozystack/external-apps-example) - follow-up: - [ ] [cozystack/examples](https://github.com/cozystack/examples) - follow-up: ### Release note ```release-note test(e2e): stamp each tenant worker guest console capture with the instant it was read and the instant its guest started, and take the same capture on passing runs so a failing boot has a healthy one to be compared against ``` <!-- This is an auto-generated comment: release notes by coderabbit.ai --> ## Summary by CodeRabbit * **Diagnostics** * Improved Kubernetes serial-console diagnostics with capture context, bounded collection, per-read timestamps, and cluster-wide Pod start-time timelines. * Added clearer reporting for incomplete, unavailable, or failed diagnostic data. * Added absolute timestamps and explicit time units to support reliable troubleshooting. * **Reliability** * Passing test runs now collect baseline diagnostics only when sufficient time remains, helping prevent suite timeouts. * **Tests & Documentation** * Expanded diagnostic coverage and updated documented timing expectations for supported Kubernetes versions. <!-- end of auto-generated comment: release notes by coderabbit.ai -->
This commit is contained in:
7 files changed
+865
-17
No files matched your search
@@ -105,6 +105,8 @@ Be precise about TIA's scope — it is narrower than "skip E2E for unrelated PRs
|
||||
- **A catch script needs an explicit `timeout:` that exceeds the inner budgets it contains.** A Chainsaw `script` op is bounded by `timeouts.exec` (5m in `.chainsaw.yaml`) unless it overrides it, so a catch whose own `timeout -k …` wrappers sum past that is *structurally guaranteed* to be killed — it reports `SCRIPT | ERROR | signal: killed` and yields nothing. That kill is strictly worse than an inner `timeout` firing: SIGKILL takes out the process group, so the collector dies mid-write **and** every later step in the script is skipped, whereas an inner `timeout` exits 124, leaves a partial capture on disk, and lets the rest of the catch run. Size the op timeout above the sum of the inner budgets and let the inner ones be what fires.
|
||||
- **When the sum cannot fit the op, bound the collection phase as a phase rather than raising the op.** The rule above assumes the inner budgets add up to something an op timeout can sit above. On a failure path that has accumulated collectors it stops being true — the tenant-Kubernetes node-join path in `hack/e2e-chainsaw/_lib/run-kubernetes.sh` sums past what is left of its 50m op once the bringup ahead of it and the snapshot behind it are counted, and several of its reads carry only `--request-timeout`, which bounds one HTTP request rather than a client retrying against a wedged apiserver, so parts of it have no ceiling to add up in the first place. Raising the op ceiling does not fix that shape, it postpones it: a larger ceiling multiplied by a sum that grows with every collector added is the same problem one collector later. What works instead is a wall-clock budget for the whole phase (`COZY_DIAG_PHASE_BUDGET`, with `cozy_diag_phase_start` / `cozy_diag_phase_has_time`): once it is spent, the collectors that have not started are declined out loud instead of attempted, so whatever must run after the phase — the tenant crust-gather snapshot, in that case — is never queued behind work begun past the deadline. Two consequences worth carrying to the next collector. The budget bounds when a collector may *start*, not when the phase ends, so it is not a worst case and the comment next to it must not be written as one. And because what runs last is what gets declined, source order becomes load-bearing: put the cheap reads that discriminate between failure modes ahead of the collectors that cost minutes, or the budget will spend itself on the expensive ones and drop the evidence the path exists to produce.
|
||||
- **Set `crust-gather --duration` explicitly.** It is crust-gather's own budget for the collection phase and it defaults to **60s**; on elapse it abandons the collection and skips its finish step, leaving a partial tree with nothing to say the rest is missing. The outer wall-clock must exceed it, because the API discovery crust-gather runs *first* is not covered by that budget at all — with an unhealthy aggregated APIService (the state a failed e2e is usually in) aggregated discovery times out and the fallback re-walks every group, which can consume the entire outer timeout before a single object is written. Do not diagnose a killed snapshot by bumping the outer number alone; the two budgets bound different phases. Send the collector's output to a log inside the snapshot rather than `/dev/null` so "complete or truncated?" is answerable from the artifact.
|
||||
- **A collector that only runs on failure answers in one direction.** Its output has no measured value to be read against, so a claim like "this boot was slow" rests on an impression of what a healthy run looks like rather than on a number from one. Where the evidence is destroyed by teardown — the tenant worker's guest serial console goes with the Pod that holds the stream — the baseline has to be taken on the passing run or it does not exist at all, which is why `hack/e2e-chainsaw/_lib/run-kubernetes.sh` captures that console on both paths and records which one it was. A passing-path collector is held to two rules the failure path does not need. It must not fail the suite, since everything the suite exists to prove has already passed by the time it runs — and its own cost counts, not just its exit status, so a collector that costs minutes declines itself out loud when the operation's ceiling no longer has room for what it is about to spend, rather than starting a walk that the ceiling cuts off mid-write. That bounds the collector's contribution and nothing else: work already on the path with no ceiling of its own stays unbounded, and no reserve makes it fit by arithmetic. And what it could not collect **at all** has to reach the **job log**, not only the report, because a green run's artifact is the one nobody downloads. Per-read outcomes stay beside the read in the report, as everywhere else in that collector: a note about one console is only usable next to that console, while a walk that collected nothing is a fact about the run.
|
||||
- **A diagnostic that carries a relative clock also has to carry the absolute one.** A guest kernel stamps its console in seconds since its own boot, so a log that ends at 500 seconds says how far that guest got and nothing about when. Whether it stopped early because it started late or because it stopped printing is decided by the instant the read happened and the instant the guest started, and neither is in the file: the first survives only as the artifact's mtime, which is metadata rather than content and so is invisible to anyone reading the log and lost by anything that regenerates it, and the second only in a `describe` dump that a healthy-looking capture never triggers. Write both beside the capture, and name the units on each — an epoch integer and an RFC 3339 string subtract to nonsense if a reader takes them as printed.
|
||||
- **Per-failed-test crust-gather snapshots** are the richest diagnostic — a `crust-gather serve`-able archive of the cluster *at the moment of failure*, before cleanup. The global `error.catch` in `hack/e2e-chainsaw/.chainsaw.yaml` captures the **host** cluster into `_out/cozyreport/snapshots/<test>/host` on any failure (the Chainsaw analog of the `hack/cozytest.sh` EXIT-trap snapshot used by the e2e BATS suites); the kubernetes suites additionally snapshot their **tenant** cluster from `hack/e2e-chainsaw/_lib/run-kubernetes.sh` while the tenant API LB is still routable. `hack/cozyreport.sh` folds `snapshots/` into the artifact. Do not remove the global catch — without it the Chainsaw suite uploads a report with no per-test cluster state.
|
||||
|
||||
### 9. Keep the test environment deterministic
|
||||
|
||||
@@ -820,18 +820,43 @@ cozy_assert_guest_console_attached() {
|
||||
# to this test costs one extra file named after itself and nothing else; at
|
||||
# the cap it can displace one of this suite's own, since kubectl returns the
|
||||
# list name-sorted. COLLECTION-TRUNCATED.txt is what keeps that visible.
|
||||
#
|
||||
# Takes the context it was called in, because it is called from both paths and
|
||||
# both write here. On the failure path the console is the evidence; on the
|
||||
# passing path it is the baseline that evidence is read against, and the two are
|
||||
# the same files in the same directory. Which one a tarball holds is otherwise
|
||||
# recoverable only from the run's verdict somewhere else entirely, so the
|
||||
# capture states it.
|
||||
cozy_capture_tenant_serial_console() {
|
||||
local context="$1"
|
||||
# How many Pods the walk may cover, taken from the caller because the two
|
||||
# paths have different room. The failure path runs inside a phase whose budget
|
||||
# is derived against the whole op, so it can afford the pool at its maximum.
|
||||
# The passing path has no phase and no budget of its own: it runs inside the
|
||||
# same operation whose ceiling the suite has already spent most of, and a
|
||||
# diagnostic that turns a suite green-then-red for running long would be worse
|
||||
# than the missing baseline it exists to collect. So that caller asks for the
|
||||
# pool's minimum, which is what a boot baseline needs -- two workers booting
|
||||
# is the same measurement as ten -- and the cap that fires records what it
|
||||
# dropped either way.
|
||||
local max_pods="$2"
|
||||
local report_dir="${COZY_REPORT_DIR:-/workspace/_out/cozyreport}/snapshots/${COZY_SNAPSHOT_NAME:-kubernetes}/tenant-serial-console"
|
||||
local pods pod rc
|
||||
local list_rc=0
|
||||
local seen=0
|
||||
local walked=0
|
||||
local silent=0
|
||||
local pod_err
|
||||
local max_pods=6
|
||||
local cut_short=0
|
||||
local pod_err read_at read_done
|
||||
local timeline timeline_err timeline_why timeline_rc=0 timeline_err_kept=0
|
||||
local err_log="${report_dir}/setup-error.log"
|
||||
local warn_log="${report_dir}/READ-WARNINGS.txt"
|
||||
|
||||
mkdir -p "${report_dir}"
|
||||
# Written before the first read, not after the walk: the outcome this most
|
||||
# needs to be legible in is the one where nothing was captured, and every
|
||||
# early return below leaves the directory holding a note alone.
|
||||
printf '%s\n' "${context}" >"${report_dir}/CAPTURE-CONTEXT.txt"
|
||||
# stderr goes to its own file rather than being folded into the captured
|
||||
# stdout: a warning kubectl prints on an otherwise successful call would
|
||||
# otherwise be read back as a Pod name. Which file it goes to is decided by
|
||||
@@ -863,7 +888,8 @@ cozy_capture_tenant_serial_console() {
|
||||
return 1
|
||||
fi
|
||||
|
||||
# Cap the walk. Every read here is bounded, but the pool can reach maxReplicas, so
|
||||
# Cap the walk, at the number the caller asked for. Every read here is bounded,
|
||||
# but the pool can reach maxReplicas, so
|
||||
# an uncapped loop is a term whose size the cluster sets rather than this file --
|
||||
# inside a failure path that has to reach the tenant snapshot at the end of it.
|
||||
# The phase budget beside COZY_DIAG_PHASE_BUDGET is what stops the collectors as a
|
||||
@@ -880,6 +906,14 @@ cozy_capture_tenant_serial_console() {
|
||||
>"${report_dir}/COLLECTION-TRUNCATED.txt"
|
||||
break
|
||||
fi
|
||||
# Counted after the cap test, not from it. `seen` is incremented before that
|
||||
# test so it can fire on the Pod past the cap, which leaves it one higher
|
||||
# than the number of Pods read whenever the walk truncates. Reporting a
|
||||
# count of silent consoles against it would state a denominator that is
|
||||
# neither what was read nor what matched -- and the truncation marker beside
|
||||
# the capture prints both correctly, so the job log and the artifact would
|
||||
# disagree on a run nobody opens the artifact for.
|
||||
walked=$((walked + 1))
|
||||
echo "--- capturing guest serial console: ${pod} ---"
|
||||
rc=0
|
||||
# stderr goes beside the capture, not into it. Folded in, kubectl's own
|
||||
@@ -891,9 +925,11 @@ cozy_capture_tenant_serial_console() {
|
||||
# read above decides it: kubectl writes warnings on stderr with a zero
|
||||
# status too, and a warning beside a healthy capture is not an error.
|
||||
pod_err="${report_dir}/${pod}.read-error.log"
|
||||
read_at=$(date +%s)
|
||||
timeout -k 5 30 kubectl -n tenant-test logs "${pod}" \
|
||||
-c guest-console-log --limit-bytes=1048576 \
|
||||
>"${report_dir}/${pod}.log" 2>"${pod_err}" || rc=$?
|
||||
read_done=$(date +%s)
|
||||
if [ ! -s "${pod_err}" ]; then
|
||||
rm -f "${pod_err}"
|
||||
pod_err=
|
||||
@@ -925,6 +961,11 @@ cozy_capture_tenant_serial_console() {
|
||||
>>"${report_dir}/${pod}.log"
|
||||
elif [ "${rc}" -ne 0 ]; then
|
||||
silent=$((silent + 1))
|
||||
# Counted apart as well as together. `silent` gates the Pod-state read
|
||||
# below, and a console cut off part way needs that read as much as an
|
||||
# empty one does; but it is not silence, and the summary line these feed
|
||||
# would otherwise report bytes that arrived as bytes that never did.
|
||||
cut_short=$((cut_short + 1))
|
||||
if [ -n "${pod_err}" ]; then
|
||||
printf '%s\n' \
|
||||
'console output is truncated; see read-error.log and POD-STATE.txt' \
|
||||
@@ -935,9 +976,106 @@ cozy_capture_tenant_serial_console() {
|
||||
>>"${report_dir}/${pod}.log"
|
||||
fi
|
||||
fi
|
||||
printf '\n[capture exit code: %s]\n' "${rc}" >>"${report_dir}/${pod}.log"
|
||||
# The wall clock the log's own stamps have to be read against. Every line a
|
||||
# guest prints is stamped in seconds since that guest's kernel started, so
|
||||
# the file says how far the guest had got and nothing about when that was.
|
||||
# Paired with the compute container's start in CAPTURE-TIMELINE.txt beside
|
||||
# it, this turns the two questions a short console raises -- a guest that
|
||||
# started too late to reach a milestone, or one that reached it and then
|
||||
# went quiet -- into one subtraction. The read instant is otherwise nowhere
|
||||
# in the file: it survives as the artifact's mtime, which is metadata rather
|
||||
# than content, so a reader who opens the log sees nothing and anything that
|
||||
# regenerates or rewrites the file loses it.
|
||||
# Same bracket form the cAdvisor captures use, and for the same
|
||||
# reason: the stream is drained somewhere between the two instants, so an
|
||||
# age computed against either end is exact to the width of the bracket.
|
||||
printf '\n[console read started at %s and returned at %s epoch seconds]\n' \
|
||||
"${read_at}" "${read_done}" >>"${report_dir}/${pod}.log"
|
||||
printf '[capture exit code: %s]\n' "${rc}" >>"${report_dir}/${pod}.log"
|
||||
done
|
||||
|
||||
# When each guest started, read once for the whole selector rather than per
|
||||
# Pod, like the Pod-state read below and for the same reason: several workers
|
||||
# are one finding and paying per Pod would put back the unbounded term the cap
|
||||
# removed. Unlike that read this one is unconditional, because the question it
|
||||
# answers is raised by a console that arrived intact just as much as by one
|
||||
# that did not -- a full log ending mid-boot is the shape this failure keeps
|
||||
# producing, and it is the shape that says nothing on its own.
|
||||
#
|
||||
# Both container starts, not just compute's: the guest's clock begins with
|
||||
# compute, and the console container starting later or restarting would mean
|
||||
# the stream missed a stretch the guest did print, which reads identically to
|
||||
# a guest that was quiet.
|
||||
#
|
||||
# The console container is asked for in both status lists, the way the attach
|
||||
# check asks for it in both spec lists. KubeVirt runs it as an init container
|
||||
# today, so its runtime state is under initContainerStatuses and reading only
|
||||
# containerStatuses returns empty for a container that started fine, which
|
||||
# costs the field its meaning. Missing keys are not an error for a jsonpath
|
||||
# template, so naming both costs an empty string on whichever list does not
|
||||
# hold it.
|
||||
#
|
||||
# Both fields read the RUNNING instance, so a container that has since
|
||||
# terminated reads empty here even though it ran. The legend says so rather
|
||||
# than the query chasing lastState as well: what this pairs with is a console
|
||||
# that was read from a live Pod, and a second start time for an instance whose
|
||||
# console is not the one in the file beside it would be read as the same
|
||||
# quantity.
|
||||
timeline="${report_dir}/CAPTURE-TIMELINE.txt"
|
||||
timeline_err="${report_dir}/CAPTURE-TIMELINE-warnings.txt"
|
||||
{
|
||||
printf '=== when each tenant worker guest started, against the reads above ===\n'
|
||||
printf '%s\n' \
|
||||
'each console log carries the instant its own read returned, in epoch seconds; the times below are RFC 3339, so convert before subtracting rather than comparing the two as printed. computeStartedAt subtracted from that instant is how long the guest had been alive when it was read; compare the result against the last [ ss.ssssss] stamp in the log, which counts from the same start. Close together means the guest was still printing when the read ran, so the log ends because the guest had not got further. Far apart means the console stopped growing for the difference, which is the guest going quiet or the stream no longer carrying it; consoleStartedAt is what separates those, since a console container that started late or restarted missed whatever the guest printed before it. Read that against CAPTURE-CONTEXT.txt before calling it a finding: on a capture taken after a suite passed, the guest finished booting long before the read and a large difference is what a healthy worker looks like, so what is worth comparing there is the guest seconds each milestone landed at rather than the size of the gap. These are the running instances only: a Pod whose compute has no start time has no compute container running now, which is not the same as never having had one, and phase beside it is what says which'
|
||||
} >"${timeline}"
|
||||
# Bounded like every read here, and its stderr kept out of the file for the
|
||||
# same reason the reads above keep theirs out: the success probe below matches
|
||||
# on the row prefix, and a warning kubectl writes beside a healthy read would
|
||||
# otherwise be sitting inside the rows it is supposed to be distinguished
|
||||
# from.
|
||||
timeout -k 5 30 kubectl -n tenant-test get pods -l kubevirt.io=virt-launcher \
|
||||
-o jsonpath='{range .items[*]}{"name="}{.metadata.name}{" phase="}{.status.phase}{" podStartTime="}{.status.startTime}{" computeStartedAt="}{.status.containerStatuses[?(@.name=="compute")].state.running.startedAt}{" consoleStartedAt="}{.status.initContainerStatuses[?(@.name=="guest-console-log")].state.running.startedAt}{.status.containerStatuses[?(@.name=="guest-console-log")].state.running.startedAt}{"\n"}{end}' \
|
||||
--request-timeout=30s >>"${timeline}" 2>>"${timeline_err}" || timeline_rc=$?
|
||||
timeline_err_kept=0
|
||||
if [ ! -s "${timeline_err}" ]; then
|
||||
rm -f "${timeline_err}"
|
||||
elif [ "${timeline_rc}" -ne 0 ]; then
|
||||
if mv "${timeline_err}" "${report_dir}/CAPTURE-TIMELINE-error.log" 2>/dev/null; then
|
||||
timeline_err_kept=1
|
||||
fi
|
||||
fi
|
||||
# Three outcomes, three labels, because only one of them says anything about
|
||||
# the guests. A read that failed is a statement about this machine's view of
|
||||
# the cluster; a read that answered with nothing is a statement about the
|
||||
# namespace; and neither may be left as an absent file, which reads as a
|
||||
# capture that had no reason to write one. The failed arm is tested for rows
|
||||
# as well, because a read cut off part way leaves both -- and a note saying
|
||||
# nothing was observed, sitting under rows that plainly were, is a file that
|
||||
# contradicts itself.
|
||||
# The error file is named only when there is one. `timeout` kills the child
|
||||
# without a word, so this read can fail having written to neither stream, and
|
||||
# a note pointing at a file that was never created sends the reader looking
|
||||
# for evidence that does not exist -- the same trap the per-Pod notes above
|
||||
# avoid the same way.
|
||||
if [ "${timeline_err_kept}" -eq 1 ]; then
|
||||
timeline_why='; the reason it gave is in CAPTURE-TIMELINE-error.log'
|
||||
else
|
||||
timeline_why='; it gave no reason on either stream'
|
||||
fi
|
||||
if [ "${timeline_rc}" -ne 0 ] && grep -q '^name=' "${timeline}"; then
|
||||
printf '%s\n' \
|
||||
"the start-time read was cut off (exit ${timeline_rc}); the rows above are a prefix and the Pods missing from them were not observed${timeline_why}" \
|
||||
>>"${timeline}"
|
||||
elif [ "${timeline_rc}" -ne 0 ]; then
|
||||
printf '%s\n' \
|
||||
"the start-time read failed (exit ${timeline_rc}); when these guests started was not observed, which is not the same as their having no start time${timeline_why}" \
|
||||
>>"${timeline}"
|
||||
elif ! grep -q '^name=' "${timeline}"; then
|
||||
printf '%s\n' \
|
||||
'the start-time read succeeded and returned no rows; the walk above read consoles from Pods this selector no longer matches' \
|
||||
>>"${timeline}"
|
||||
fi
|
||||
|
||||
# An empty console log has two causes that are indistinguishable in the log
|
||||
# itself: the guest printed nothing, or the container never started and there
|
||||
# was no stream to read. The second is what kubevirt/kubevirt#15989 produces,
|
||||
@@ -948,6 +1086,13 @@ cozy_capture_tenant_serial_console() {
|
||||
# selector rather than per Pod: several silent workers are one finding, and
|
||||
# paying per Pod would put back the unbounded term the cap removed.
|
||||
if [ "${silent}" -gt 0 ]; then
|
||||
# Said on stdout as well as in the report, because the two callers read
|
||||
# different things. On the failure path the report is opened either way; on
|
||||
# the passing path it is not opened at all, and a baseline that came back
|
||||
# empty there would otherwise be visible only to whoever downloads a green
|
||||
# run's artifact -- which is nobody. The count is not a failure: on the
|
||||
# failure path a guest that printed nothing is itself a finding.
|
||||
echo "» of the ${walked} guest consoles read, $((silent - cut_short)) came back empty and ${cut_short} were cut short; see POD-STATE.txt beside the capture"
|
||||
{
|
||||
printf '=== describe pods -l kubevirt.io=virt-launcher ===\n'
|
||||
timeout -k 5 30 kubectl -n tenant-test describe pods \
|
||||
@@ -1971,6 +2116,39 @@ COZY_DIAG_RATE_INTERVAL_DEFAULT=12
|
||||
# rather than merit -- the note at the read says why, and says that merging
|
||||
# would improve both the cost and what a tight run collects.
|
||||
COZY_DIAG_PHASE_BUDGET_DEFAULT=420
|
||||
|
||||
# The operation both kubernetes-*/chainsaw-test.yaml give the script, and the
|
||||
# room the passing-path console baseline needs inside it. Constants rather than
|
||||
# knobs: neither is a budget a caller tunes, they are a restatement of a ceiling
|
||||
# that lives in the suite files, and the guard in
|
||||
# hack/run-kubernetes-serial-console_test.bats reads both sides so a suite that
|
||||
# changes its `timeout:` fails there rather than silently leaving the reserve
|
||||
# measured against a ceiling that moved.
|
||||
#
|
||||
# The reserve is the capture's own cost at the cap that caller asks for -- a
|
||||
# listing, two console reads, the two Pod-state reads a silent console triggers
|
||||
# and the start-time read, six at the 30s bound and 5s kill grace, so 210s --
|
||||
# plus a minute. It buys one thing: a run that is already near the ceiling
|
||||
# declines the baseline instead of being killed while collecting it, because a
|
||||
# suite that proved everything it exists to prove must not go red over a
|
||||
# debugging aid.
|
||||
#
|
||||
# The extra minute is slack, not a bound on what follows. The teardown between
|
||||
# this capture and the end of the function carries no wall-clock ceiling of its
|
||||
# own -- `--wait=false` bounds what the deletes wait for, not how long the
|
||||
# request itself may hang -- so no finite reserve makes the tail of a run fit by
|
||||
# arithmetic. That is pre-existing and tracked in cozystack/cozystack#3666; what
|
||||
# the reserve bounds is this capture's own contribution to the ceiling, which is
|
||||
# the part this file added.
|
||||
COZY_OP_CEILING=3000
|
||||
COZY_GREEN_CAPTURE_RESERVE=270
|
||||
# Zero until run_kubernetes_test stamps it. Declared here so the arithmetic in
|
||||
# cozy_green_capture_has_room cannot meet an unbound name: under the `set -eu`
|
||||
# the chainsaw script runs with, that aborts the whole function, which is the
|
||||
# very outcome -- a passing run ending red -- the reserve exists to prevent. A
|
||||
# zero left in place fails closed rather than quietly: the elapsed time it
|
||||
# implies is the whole epoch, so the capture is declined and says so.
|
||||
_COZY_RUN_STARTED_AT=0
|
||||
COZY_DIAG_READ_TIMEOUT=$(_cozy_diag_seconds "${COZY_DIAG_READ_TIMEOUT:-$COZY_DIAG_READ_TIMEOUT_DEFAULT}" "$COZY_DIAG_READ_TIMEOUT_DEFAULT" COZY_DIAG_READ_TIMEOUT positive)
|
||||
# Validated too, though a suffix is not what breaks it: `timeout -k abc 20` exits 125
|
||||
# before running the command at all, so a non-numeric grace makes every read in the
|
||||
@@ -2099,6 +2277,33 @@ cozy_diag_phase_has_time() {
|
||||
return 1
|
||||
}
|
||||
|
||||
# cozy_green_capture_has_room <what>: 0 while the operation can still afford
|
||||
# <what> on the PASSING path, 1 once it cannot -- and on 1 it says which
|
||||
# collector was declined and why.
|
||||
#
|
||||
# The failure path's counterpart above bounds a phase against a budget of its
|
||||
# own. This one has no phase to bound: it runs after everything the suite
|
||||
# proves, inside an operation whose ceiling the bringup ahead of it has already
|
||||
# spent an unknown share of. So the quantity is what is LEFT of that ceiling,
|
||||
# and the only way to know it is the stamp taken when the function began.
|
||||
#
|
||||
# A function rather than two lines at the call site, because the direction of
|
||||
# the comparison is the whole safety property and a predicate is something a
|
||||
# test can drive both ways. Inlined, the only coverage available is a grep for
|
||||
# the line, which passes just as well when the comparison is inverted -- and an
|
||||
# inverted one runs the capture on exactly the runs that cannot afford it.
|
||||
cozy_green_capture_has_room() {
|
||||
local elapsed=$(( $(date +%s) - _COZY_RUN_STARTED_AT ))
|
||||
|
||||
[ "$(( COZY_OP_CEILING - elapsed ))" -lt "${COZY_GREEN_CAPTURE_RESERVE}" ] || return 0
|
||||
# States the room asked for rather than the cost, because those are different
|
||||
# numbers and the gate compares against the first: the reserve is the capture's
|
||||
# own worst case plus slack, so reporting it as what the capture costs would
|
||||
# overstate the collector by the slack every time this fires.
|
||||
echo "» ${1}: not collected — ${elapsed}s of the ${COZY_OP_CEILING}s operation are spent and this needs ${COZY_GREEN_CAPTURE_RESERVE}s of room to start; nothing here was observed either way" >&2
|
||||
return 1
|
||||
}
|
||||
|
||||
# cozy_diag_read <label> <command...>: run one diagnostic read under a wall-clock
|
||||
# bound, and name the outcome when it does not finish. Used by both on-failure
|
||||
# blocks in run_kubernetes_test, which end in the same `exit 1` and so depend on
|
||||
@@ -2413,7 +2618,7 @@ cozy_report_node_join_failure() {
|
||||
# disable by design and the green path asserts it attached.
|
||||
if cozy_diag_phase_has_time '(b1) tenant worker guest serial console'; then
|
||||
echo "=== (b1) tenant worker guest serial console (management cluster, ns tenant-test) ==="
|
||||
cozy_capture_tenant_serial_console || true
|
||||
cozy_capture_tenant_serial_console 'node-join failed: captured after fewer than 2 tenant nodes became Ready inside the deadline' 6 || true
|
||||
fi
|
||||
|
||||
# (d) What the workers got, what they were denied, and what the sandbox nodes
|
||||
@@ -2562,6 +2767,14 @@ run_kubernetes_test() {
|
||||
local k8s_version
|
||||
k8s_version=$(yq "$version_expr" packages/apps/kubernetes/files/versions.yaml)
|
||||
|
||||
# Stamped here because the passing path below spends wall clock on a
|
||||
# diagnostic after everything the suite proves has already passed, and the
|
||||
# operation it runs inside has a fixed ceiling. What that costs is bounded;
|
||||
# what is LEFT of the ceiling by then is not, so the only way the capture can
|
||||
# be prevented from turning a green run red is to know how long this has been
|
||||
# running. Nothing else reads it.
|
||||
_COZY_RUN_STARTED_AT=$(date +%s)
|
||||
|
||||
# Clean up stale resources from a previous failed retry
|
||||
kubectl -n tenant-test delete kuberneteses.apps.cozystack.io "${test_name}" --ignore-not-found --wait=false 2>/dev/null || true
|
||||
kubectl -n tenant-test wait kuberneteses.apps.cozystack.io "${test_name}" --for=delete --timeout=2m 2>/dev/null || true
|
||||
@@ -3392,6 +3605,48 @@ EOF
|
||||
exit 1
|
||||
fi
|
||||
|
||||
# The same capture the failure path takes, on the run that succeeded. Every
|
||||
# console this tree has collected came from a failure, so what a healthy
|
||||
# worker's boot looks like -- which stages it goes through and how long each
|
||||
# takes -- has never been measured, and "slower than usual" is the claim the
|
||||
# node-join failure keeps resting on. This is where the value it is compared
|
||||
# against comes from, and it exists only until the tenant below is deleted:
|
||||
# the container holding the stream goes with the Pod, and no read recovers it
|
||||
# afterwards.
|
||||
#
|
||||
# Not gated by the diagnostics phase budget, which covers the failure path and
|
||||
# the snapshot behind it. Every read here is bounded individually and none of
|
||||
# them as a group, so the honest ceiling is the listing, one read per Pod at
|
||||
# the cap this caller asks for, the two Pod-state reads a silent console
|
||||
# triggers and the start-time read -- six reads at the 30s bound and 5s kill
|
||||
# grace, so 210s, against a run that has finished everything it exists to
|
||||
# prove and typically has minutes of its operation left. The wedge check is
|
||||
# not in that count: it belongs to the failure path, and this caller reaches
|
||||
# here only after the attach check above has already answered the question it
|
||||
# asks. Asking for the pool's minimum rather than the pool is what keeps that
|
||||
# number small.
|
||||
#
|
||||
# It is still declined rather than attempted when the operation no longer has
|
||||
# room for it, which is what keeps "must not fail the suite" true of a
|
||||
# collector whose cost is real: everything above has passed by here, so a run
|
||||
# killed at the op ceiling while collecting a debugging aid would report the
|
||||
# suite as broken on the strength of the aid. Where the reserve comes from is
|
||||
# written beside the constant rather than repeated here.
|
||||
if cozy_green_capture_has_room 'the tenant worker guest console baseline'; then
|
||||
echo "» capturing the tenant worker guest console before teardown"
|
||||
if ! cozy_capture_tenant_serial_console 'the suite passed: captured after the last assertion and before tenant teardown' 2; then
|
||||
# Said in the job log rather than only in the report, because a green run
|
||||
# is the one nobody opens the report for. This branch covers the two setup
|
||||
# failures the capture returns non-zero for, the Pod listing failing and
|
||||
# no virt-launcher Pod matching; a walk that ran and came back with empty
|
||||
# consoles returns zero and is reported by the capture's own line about
|
||||
# how many said nothing. It does not fail the suite: this captures a
|
||||
# debugging aid, and everything the suite exists to prove has already
|
||||
# passed by here.
|
||||
echo "» WARNING: the guest console capture failed on a passing run; the boot baseline is missing from this report, see the notes beside the capture" >&2
|
||||
fi
|
||||
fi
|
||||
|
||||
# Success: disarm the tenant-snapshot trap so it doesn't fire on the clean exit.
|
||||
trap - EXIT
|
||||
# Clean up: delete the test-scoped tenant API LoadBalancer (frees its MetalLB
|
||||
|
||||
@@ -33,7 +33,7 @@ spec:
|
||||
# than the reads that discriminate between failure modes:
|
||||
# node-join diagnostics reads
|
||||
# worker network counters
|
||||
# serial-console family (~5m50s at worst, ~3m30s at the pool's minimum)
|
||||
# serial-console family (~6m25s at worst, ~4m05s at the pool's minimum)
|
||||
# worker CPU usage and throttling counters, two samples
|
||||
# sandbox node CPU time, two samples
|
||||
# (those two alternate rather than run to completion in turn: both
|
||||
|
||||
@@ -27,7 +27,7 @@ spec:
|
||||
# than the reads that discriminate between failure modes:
|
||||
# node-join diagnostics reads
|
||||
# worker network counters
|
||||
# serial-console family (~5m50s at worst, ~3m30s at the pool's minimum)
|
||||
# serial-console family (~6m25s at worst, ~4m05s at the pool's minimum)
|
||||
# worker CPU usage and throttling counters, two samples
|
||||
# sandbox node CPU time, two samples
|
||||
# (those two alternate rather than run to completion in turn: both
|
||||
|
||||
@@ -724,7 +724,7 @@ run_capture() {
|
||||
# started rather than cut short -- and the console is the only capture that
|
||||
# survives a worker which never reached apid, the shape this failure usually
|
||||
# takes. Cost, not worth, is what puts it here.
|
||||
console=$(grep -n 'cozy_capture_tenant_serial_console || true' "$lib" | head -n 1 | cut -d: -f1)
|
||||
console=$(grep -n "cozy_capture_tenant_serial_console 'node-join failed" "$lib" | head -n 1 | cut -d: -f1)
|
||||
if [ -z "$console" ]; then
|
||||
echo "expected the failure block to still capture the guest serial console" >&2
|
||||
return 1
|
||||
|
||||
@@ -1108,7 +1108,7 @@ assert_file_lacks_pattern() {
|
||||
# capture can spend the whole budget between them. With
|
||||
# (c) last, the budget declines the answer and keeps the noise.
|
||||
csr=$(grep -n "cozy_diag_read 'tenant CSR list'" "$lib" | head -n 1 | cut -d: -f1)
|
||||
console=$(grep -n 'cozy_capture_tenant_serial_console || true' "$lib" | head -n 1 | cut -d: -f1)
|
||||
console=$(grep -n "cozy_capture_tenant_serial_console 'node-join failed" "$lib" | head -n 1 | cut -d: -f1)
|
||||
talos=$(grep -n 'cozy_capture_tenant_talos "${test_name}" || true' "$lib" | head -n 1 | cut -d: -f1)
|
||||
for v in csr console talos; do
|
||||
eval "n=\$$v"
|
||||
@@ -1147,7 +1147,7 @@ assert_file_lacks_pattern() {
|
||||
# so cost decides it rather than taste. The companion guard is the one that
|
||||
# bounds what may sit ahead of the console at all.
|
||||
net=$(grep -n 'cozy_capture_tenant_worker_network_counters || true' "$lib" | head -n 1 | cut -d: -f1)
|
||||
console=$(grep -n 'cozy_capture_tenant_serial_console || true' "$lib" | head -n 1 | cut -d: -f1)
|
||||
console=$(grep -n "cozy_capture_tenant_serial_console 'node-join failed" "$lib" | head -n 1 | cut -d: -f1)
|
||||
cpu=$(grep -n 'cozy_capture_tenant_worker_cpu_throttle "${_sample}" || true' "$lib" | head -n 1 | cut -d: -f1)
|
||||
talos=$(grep -n 'cozy_capture_tenant_talos "${test_name}" || true' "$lib" | head -n 1 | cut -d: -f1)
|
||||
mirror=$(grep -n 'ghcr_mirror_diagnose || true' "$lib" | head -n 1 | cut -d: -f1)
|
||||
@@ -1180,7 +1180,7 @@ assert_file_lacks_pattern() {
|
||||
#
|
||||
# Two claims, because one of them is structural and the other is arithmetic
|
||||
# and neither implies the other.
|
||||
console=$(grep -n 'cozy_capture_tenant_serial_console || true' "$lib" | head -n 1 | cut -d: -f1)
|
||||
console=$(grep -n "cozy_capture_tenant_serial_console 'node-join failed" "$lib" | head -n 1 | cut -d: -f1)
|
||||
if [ -z "$console" ]; then
|
||||
echo "expected the failure path to capture the guest serial console" >&2
|
||||
return 1
|
||||
|
||||
@@ -23,15 +23,43 @@ mktemp_fail=0
|
||||
kubectl_logs_output='mock console output'
|
||||
kubectl_logs_rc=0
|
||||
kubectl_logs_stderr=
|
||||
kubectl_timeline_rows='name=virt-launcher-worker-a-11111 phase=Running podStartTime=2026-08-15T14:35:26Z computeStartedAt=2026-08-15T14:35:47Z consoleStartedAt=2026-08-15T14:35:47Z'
|
||||
kubectl_timeline_rc=0
|
||||
kubectl_timeline_stderr=
|
||||
talosctl_calls=/dev/null
|
||||
timeout_calls=/dev/null
|
||||
timeout_fail_pod=
|
||||
date_now=
|
||||
|
||||
date() {
|
||||
# Same shape the node-join suite uses: a fixed clock so the passing path's
|
||||
# remaining-time arithmetic is decided by the test rather than by when it ran.
|
||||
if [ -n "${date_now}" ] && [ "${1:-}" = +%s ]; then
|
||||
printf '%s\n' "${date_now}"
|
||||
return 0
|
||||
fi
|
||||
command date "$@"
|
||||
}
|
||||
|
||||
kubectl() {
|
||||
printf '%s\n' "$*" >>"${kubectl_calls}"
|
||||
|
||||
if [ "${3:-}" = get ] && [ "${4:-}" = pods ]; then
|
||||
case "$*" in
|
||||
*computeStartedAt*)
|
||||
# Rows first, status after, so a cut-off read can be modelled as what it
|
||||
# is: a prefix that arrived plus a non-zero status. Returning early on
|
||||
# the status instead would make "failed" and "returned nothing" the same
|
||||
# scenario, and the branch that tells them apart untestable.
|
||||
#
|
||||
# stderr is staged separately for the same reason every other arm here
|
||||
# stages it: kubectl writes warnings beside a healthy read as well as
|
||||
# errors beside a failed one, and which file those land in is decided by
|
||||
# the status rather than by anything in the text.
|
||||
[ -z "${kubectl_timeline_stderr}" ] || printf '%s\n' "${kubectl_timeline_stderr}" >&2
|
||||
[ -z "${kubectl_timeline_rows}" ] || printf '%s\n' "${kubectl_timeline_rows}"
|
||||
return "${kubectl_timeline_rc}"
|
||||
;;
|
||||
*initContainerStatuses*)
|
||||
[ -z "${kubectl_wedge_stderr}" ] || printf '%s\n' "${kubectl_wedge_stderr}" >&2
|
||||
[ "${kubectl_wedge_rc}" -eq 0 ] || return "${kubectl_wedge_rc}"
|
||||
@@ -124,7 +152,7 @@ assert_file_lacks_pattern() {
|
||||
# put in them.
|
||||
run_capture() {
|
||||
local _rc=0
|
||||
( set +x; cozy_capture_tenant_serial_console ) || _rc=$?
|
||||
( set +x; cozy_capture_tenant_serial_console "${1:-capture staged by a unit test}" "${2:-6}" ) || _rc=$?
|
||||
return "${_rc}"
|
||||
}
|
||||
|
||||
@@ -690,7 +718,8 @@ run_capture() {
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=console-truncated
|
||||
|
||||
run_capture
|
||||
out=$( ( set +x; cozy_capture_tenant_serial_console 'a unit test' 6 ) 2>/dev/null )
|
||||
printf '%s\n' "$out" >"$tmp/out"
|
||||
|
||||
# The read broke off mid-stream, so the file holds a prefix. Calling that
|
||||
# "no console output" is the same unestablished claim about silence the
|
||||
@@ -699,6 +728,13 @@ run_capture() {
|
||||
assert_file_contains 'mock console output' "$f"
|
||||
assert_file_contains 'truncated' "$f"
|
||||
assert_file_lacks_pattern 'no console output' "$f"
|
||||
# And the summary line the passing path reads must not undo that. It is fed
|
||||
# by the same counter that gates the Pod-state read, which a cut-short console
|
||||
# needs as much as an empty one -- so counting them together is right and
|
||||
# naming them together is not. On the green path this line is the only thing
|
||||
# anyone sees, and a partial baseline reported as no baseline sends the reader
|
||||
# past evidence that is sitting in the artifact.
|
||||
assert_file_contains 'of the 1 guest consoles read, 0 came back empty and 1 were cut short' "$tmp/out"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@@ -835,11 +871,11 @@ run_capture() {
|
||||
# number: it outlives the session and is trusted by the next reader.
|
||||
for f in hack/e2e-chainsaw/kubernetes-latest/chainsaw-test.yaml \
|
||||
hack/e2e-chainsaw/kubernetes-previous/chainsaw-test.yaml; do
|
||||
grep -q '3m30s' "$f" || {
|
||||
grep -q '4m05s' "$f" || {
|
||||
echo "expected $f to state the minReplicas-2 cost including the wedge and Pod-state reads" >&2
|
||||
return 1
|
||||
}
|
||||
grep -q '5m50s' "$f" || {
|
||||
grep -q '6m25s' "$f" || {
|
||||
echo "expected $f to state the worst-case cost including the wedge read" >&2
|
||||
return 1
|
||||
}
|
||||
@@ -961,7 +997,7 @@ run_capture() {
|
||||
# recovered. Ahead of the functional assertions it would let a diagnostic
|
||||
# preempt the checks the suite exists for.
|
||||
gate=$(grep -n '^ *cozy_assert_guest_console_attached || attach_rc=$?$' "$lib" | head -n 1 | cut -d: -f1)
|
||||
capture=$(grep -n '^ *cozy_capture_tenant_serial_console || true$' "$lib" | head -n 1 | cut -d: -f1)
|
||||
capture=$(grep -n "^ *cozy_capture_tenant_serial_console 'node-join failed" "$lib" | head -n 1 | cut -d: -f1)
|
||||
if [ -z "$gate" ]; then
|
||||
echo "expected the suite to verify guest-console-log attached on the passing path" >&2
|
||||
return 1
|
||||
@@ -992,7 +1028,7 @@ run_capture() {
|
||||
# Ordering is the whole point: the talosctl capture needs an apid that the
|
||||
# failure class this collects never reached, so running it first spends the
|
||||
# failure path's budget on the collector that cannot answer.
|
||||
console=$(grep -n '^ *cozy_capture_tenant_serial_console || true$' "$lib" | head -n 1 | cut -d: -f1)
|
||||
console=$(grep -n "^ *cozy_capture_tenant_serial_console 'node-join failed" "$lib" | head -n 1 | cut -d: -f1)
|
||||
talos=$(grep -n '^ *cozy_capture_tenant_talos "${test_name}" || true$' "$lib" | head -n 1 | cut -d: -f1)
|
||||
if [ -z "$console" ]; then
|
||||
echo "expected the node-join failure path to capture the guest serial console" >&2
|
||||
@@ -1008,6 +1044,561 @@ run_capture() {
|
||||
fi
|
||||
}
|
||||
|
||||
@test "the passing path captures the console too, before the tenant is torn down" {
|
||||
lib=hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
# An instrument that only runs on the failure path answers in one direction.
|
||||
# Every console this tree has ever captured came from a run that failed, so
|
||||
# the boot stages a healthy worker goes through, and how long each takes, have
|
||||
# no measured value to compare a failing run against -- and "slower than
|
||||
# usual" is the claim the failure keeps resting on. The passing run is where
|
||||
# that value comes from, and it exists only until the tenant is deleted.
|
||||
gate=$(grep -n '^ *cozy_assert_guest_console_attached || attach_rc=$?$' "$lib" | head -n 1 | cut -d: -f1)
|
||||
green=$(grep -n "^ *if ! cozy_capture_tenant_serial_console 'the suite passed" "$lib" | head -n 1 | cut -d: -f1)
|
||||
teardown=$(grep -n '^ *kubectl -n tenant-test delete kuberneteses.apps.cozystack.io "${test_name}" --ignore-not-found --wait=false' "$lib" | tail -n 1 | cut -d: -f1)
|
||||
for v in gate green teardown; do
|
||||
eval "n=\$$v"
|
||||
if [ -z "$n" ]; then
|
||||
echo "expected to locate $v in $lib" >&2
|
||||
return 1
|
||||
fi
|
||||
done
|
||||
# After the attach check, because that check is what says there is a container
|
||||
# to read; before the delete, because the Pod holding the stream goes with the
|
||||
# tenant and nothing recovers it afterwards.
|
||||
if [ "$green" -le "$gate" ] || [ "$green" -ge "$teardown" ]; then
|
||||
echo "the passing-path capture (line $green) must sit between the attach check ($gate) and the teardown ($teardown)" >&2
|
||||
return 1
|
||||
fi
|
||||
}
|
||||
|
||||
@test "the passing path asks for the pool minimum, not the pool" {
|
||||
lib=hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
# The failure path runs inside a phase whose budget is derived against the
|
||||
# whole operation, so it can afford the pool at its maximum. The passing path
|
||||
# has neither a phase nor a budget: it runs inside the same 50m operation the
|
||||
# suite has already spent most of, and every read it issues is bounded
|
||||
# individually but not as a group. A walk over the maximum pool could
|
||||
# therefore turn a suite that proved everything it exists to prove into a red
|
||||
# run for collecting a debugging aid slowly. Two workers booting is the same
|
||||
# baseline as ten, so that is what it asks for.
|
||||
green=$(grep -n "cozy_capture_tenant_serial_console 'the suite passed[^']*' 2;" "$lib" | head -n 1 | cut -d: -f1)
|
||||
red=$(grep -n "cozy_capture_tenant_serial_console 'node-join failed[^']*' 6 || true" "$lib" | head -n 1 | cut -d: -f1)
|
||||
if [ -z "$green" ]; then
|
||||
echo "expected the passing path to cap its console walk at the pool minimum" >&2
|
||||
return 1
|
||||
fi
|
||||
if [ -z "$red" ]; then
|
||||
echo "expected the failure path to keep covering the pool at its maximum" >&2
|
||||
return 1
|
||||
fi
|
||||
}
|
||||
|
||||
@test "the walk covers exactly the number of Pods the caller asked for" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-a virt-launcher-b virt-launcher-c"
|
||||
kubectl_logs_output=
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=console-cap-arg
|
||||
|
||||
out=$( ( set +x; cozy_capture_tenant_serial_console 'a unit test' 2 ) 2>/dev/null )
|
||||
printf '%s\n' "$out" >"$tmp/out"
|
||||
|
||||
# The cap is the caller's, not a literal in the walk, or the passing path
|
||||
# cannot be cheaper than the failure path and the argument above is decorative.
|
||||
dir="$COZY_REPORT_DIR/snapshots/console-cap-arg/tenant-serial-console"
|
||||
[ -f "$dir/virt-launcher-a.log" ]
|
||||
[ -f "$dir/virt-launcher-b.log" ]
|
||||
[ ! -f "$dir/virt-launcher-c.log" ]
|
||||
assert_file_contains 'capture stopped after 2 Pods; 3 matched in total' \
|
||||
"$dir/COLLECTION-TRUNCATED.txt"
|
||||
# And the count on stdout is over the Pods actually read. The cap probe runs
|
||||
# on the Pod past the cap, so the counter driving it is one higher than the
|
||||
# walk; reported as the denominator it would name a number that is neither
|
||||
# what was read nor what matched, and disagree with the truncation marker
|
||||
# written beside it -- on the path where nobody opens that marker.
|
||||
assert_file_contains 'of the 2 guest consoles read, 2 came back empty and 0 were cut short' "$tmp/out"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "a passing-path capture that failed is said out loud instead of failing the suite" {
|
||||
lib=hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
# Two failure modes, and this pins against both. Left bare, a non-zero return
|
||||
# would fail a suite that proved everything it exists to prove, on a
|
||||
# debugging aid. Silenced with `|| true`, a capture that collected nothing
|
||||
# would leave a green run whose only trace of the gap is an artifact nobody
|
||||
# opens on a green run.
|
||||
green=$(grep -n "^ *if ! cozy_capture_tenant_serial_console 'the suite passed" "$lib" | head -n 1 | cut -d: -f1)
|
||||
if [ -z "$green" ]; then
|
||||
echo "expected the passing path to capture the console through a tested call" >&2
|
||||
return 1
|
||||
fi
|
||||
# Bounded by the branch rather than by a line count: the warning is what the
|
||||
# branch is for, and a fixed offset would break on a comment being added to it
|
||||
# while a whole-file search would accept a warning belonging to something
|
||||
# else.
|
||||
warn=$(awk -v g="$green" '
|
||||
NR <= g { next }
|
||||
/^ fi$/ { exit }
|
||||
/WARNING: the guest console capture/ { print NR; exit }
|
||||
' "$lib")
|
||||
if [ -z "$warn" ]; then
|
||||
echo "expected the failed passing-path capture to warn in the job log" >&2
|
||||
return 1
|
||||
fi
|
||||
}
|
||||
|
||||
@test "the capture says which run produced it" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-worker-a-11111"
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=console-context
|
||||
|
||||
run_capture 'the suite passed: captured after the last assertion'
|
||||
|
||||
# Both paths write the same directory, and the two readings mean opposite
|
||||
# things: one is the failure being studied, the other is the baseline it is
|
||||
# compared against. Which one a tarball holds is otherwise recoverable only
|
||||
# from the run's verdict somewhere else entirely.
|
||||
assert_file_contains 'the suite passed: captured after the last assertion' \
|
||||
"$COZY_REPORT_DIR/snapshots/console-context/tenant-serial-console/CAPTURE-CONTEXT.txt"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "a walk that came back with empty consoles says so on stdout" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-worker-a-11111"
|
||||
kubectl_logs_output=
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=console-silent-count
|
||||
|
||||
out=$( ( set +x; cozy_capture_tenant_serial_console 'a unit test' 6 ) 2>/dev/null )
|
||||
printf '%s\n' "$out" >"$tmp/out"
|
||||
|
||||
# The per-pod notes and POD-STATE.txt already record this in the report, and
|
||||
# on the failure path that is enough because the report gets opened. The
|
||||
# passing path is the one that does not: a baseline that came back empty
|
||||
# there would otherwise be visible only to whoever downloads a green run's
|
||||
# artifact. The count is not a failure and the capture still returns zero, so
|
||||
# stdout is the only place the two callers share.
|
||||
assert_file_contains 'of the 1 guest consoles read, 1 came back empty and 0 were cut short' "$tmp/out"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "a healthy walk says nothing about silent consoles" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-worker-a-11111"
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=console-silent-none
|
||||
|
||||
out=$( ( set +x; cozy_capture_tenant_serial_console 'a unit test' 6 ) 2>/dev/null )
|
||||
printf '%s\n' "$out" >"$tmp/out"
|
||||
|
||||
# The other half of the pair. A line printed on every run is a line nobody
|
||||
# reads, and this one is meant to be read on the green path.
|
||||
assert_file_lacks_pattern 'guest consoles read, ' "$tmp/out"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "the context is written even when there is nothing to capture" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names=
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=console-context-empty
|
||||
rc=0
|
||||
|
||||
run_capture 'the suite passed: captured after the last assertion' || rc=$?
|
||||
|
||||
# The empty case is the one where the context matters most: a directory
|
||||
# holding only a failure note is where a reader most needs to know which run
|
||||
# left it, and the early return is the path most likely to skip writing it.
|
||||
[ "$rc" -ne 0 ]
|
||||
assert_file_contains 'the suite passed' \
|
||||
"$COZY_REPORT_DIR/snapshots/console-context-empty/tenant-serial-console/CAPTURE-CONTEXT.txt"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "each console says when it was read, so its last kernel stamp has a wall clock to sit against" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-worker-a-11111"
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=console-read-instant
|
||||
|
||||
run_capture
|
||||
|
||||
# A console log is stamped in guest seconds since the guest's own kernel
|
||||
# started, and it ends wherever the guest had got to when the read ran. Those
|
||||
# two facts alone cannot say whether a short log means a guest that started
|
||||
# late or a guest that went quiet, because the instant of the read is not in
|
||||
# the file. Without this line the only trace of it is the artifact's mtime,
|
||||
# which is metadata rather than content: nothing in the report says it, and a
|
||||
# reader has to know to go looking outside the file for it.
|
||||
f="$COZY_REPORT_DIR/snapshots/console-read-instant/tenant-serial-console/virt-launcher-worker-a-11111.log"
|
||||
assert_file_contains 'console read started at ' "$f"
|
||||
assert_file_contains ' epoch seconds' "$f"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "the capture records when each guest started, beside the console it captured" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-worker-a-11111"
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=console-timeline
|
||||
|
||||
run_capture
|
||||
|
||||
# The other end of the subtraction. With the read instant above and the
|
||||
# compute container's start here, how long the guest had been alive when the
|
||||
# console was read is one subtraction away, and comparing that against the
|
||||
# last stamp in the log says which of the two happened: a guest that had not
|
||||
# lived long enough to reach a milestone, or one that lived and stopped
|
||||
# printing. Without it both look like the same short file.
|
||||
f="$COZY_REPORT_DIR/snapshots/console-timeline/tenant-serial-console/CAPTURE-TIMELINE.txt"
|
||||
assert_file_contains 'computeStartedAt=2026-08-15T14:35:47Z' "$f"
|
||||
# The subtraction is spelled out rather than left to be reconstructed. This
|
||||
# file is read by whoever opens a failed run's tarball months later, and the
|
||||
# relation between a guest-relative kernel stamp and two absolute instants is
|
||||
# exactly the step a reader gets wrong.
|
||||
assert_file_contains 'epoch seconds' "$f"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "a start-time read that failed is named rather than left out" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-worker-a-11111"
|
||||
# Non-zero AND nothing written: the read that never got a row across, which is
|
||||
# a different fact from the one cut off part way through and takes a different
|
||||
# note. Both have to be staged explicitly or the mock decides which arm runs.
|
||||
kubectl_timeline_rc=9
|
||||
kubectl_timeline_rows=
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=console-timeline-failed
|
||||
|
||||
run_capture
|
||||
|
||||
# An absent file reads as a capture that had no reason to write one, which is
|
||||
# the silence every collector here is built to refuse. The read failing is a
|
||||
# statement about this machine's view of the cluster, not about when the
|
||||
# guests started, and the file has to say which of those it is holding.
|
||||
f="$COZY_REPORT_DIR/snapshots/console-timeline-failed/tenant-serial-console/CAPTURE-TIMELINE.txt"
|
||||
assert_file_contains 'exit 9' "$f"
|
||||
assert_file_lacks_pattern 'computeStartedAt=2026' "$f"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "a start-time read cut off part way is not reported as having observed nothing" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-worker-a-11111"
|
||||
kubectl_timeline_rc=124
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=console-timeline-cut
|
||||
|
||||
run_capture
|
||||
|
||||
# A read killed at its bound can leave rows behind and still report failure.
|
||||
# Saying "when these guests started was not observed" under start times that
|
||||
# are plainly sitting there makes the file contradict itself, and a reader who
|
||||
# believes the note discards the rows -- which for a capture that exists to be
|
||||
# subtracted is the whole value of the file.
|
||||
f="$COZY_REPORT_DIR/snapshots/console-timeline-cut/tenant-serial-console/CAPTURE-TIMELINE.txt"
|
||||
assert_file_contains 'computeStartedAt=2026-08-15T14:35:47Z' "$f"
|
||||
assert_file_contains 'cut off (exit 124)' "$f"
|
||||
assert_file_lacks_pattern 'was not observed, which is not the same' "$f"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "a start-time read that answered with nothing is not reported as a start time" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-worker-a-11111"
|
||||
kubectl_timeline_rows=
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=console-timeline-empty
|
||||
|
||||
run_capture
|
||||
|
||||
# The third outcome, and the one that looks most like success: the read
|
||||
# answered, and answered with nothing. A zero-length file here would be read
|
||||
# as a capture that ran and found the guests had no start times, which is not
|
||||
# a state a Pod can be in -- the walk above just read consoles from these
|
||||
# same Pods.
|
||||
f="$COZY_REPORT_DIR/snapshots/console-timeline-empty/tenant-serial-console/CAPTURE-TIMELINE.txt"
|
||||
assert_file_contains 'returned no rows' "$f"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "the start-time read is bounded like every other read in this capture" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-worker-a-11111"
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=console-timeline-bound
|
||||
|
||||
run_capture
|
||||
|
||||
# This read runs on the same failure path as the rest, where the apiserver is
|
||||
# the component least likely to answer. An unbounded one does not lose only
|
||||
# itself: it holds the op until the op is killed, and the tenant snapshot
|
||||
# queued behind it is lost rather than truncated.
|
||||
assert_file_contains 'computeStartedAt' "$timeout_calls"
|
||||
assert_file_contains 'request-timeout' "$kubectl_calls"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "a warning beside a healthy start-time read is not filed as an error" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-worker-a-11111"
|
||||
kubectl_timeline_stderr='Warning: v1 Pod is deprecated in this build'
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=console-timeline-warn
|
||||
|
||||
run_capture
|
||||
|
||||
# kubectl writes deprecation and partial-result warnings on stderr with a zero
|
||||
# exit, so what a message means is decided by the status and not by the fact
|
||||
# that something was written. Filed as an error, a healthy read sends the next
|
||||
# reader after a failure that did not happen; folded into the rows, it sits
|
||||
# inside the data the success probe reads.
|
||||
dir="$COZY_REPORT_DIR/snapshots/console-timeline-warn/tenant-serial-console"
|
||||
assert_file_contains 'v1 Pod is deprecated' "$dir/CAPTURE-TIMELINE-warnings.txt"
|
||||
[ ! -f "$dir/CAPTURE-TIMELINE-error.log" ]
|
||||
assert_file_lacks_pattern 'deprecated' "$dir/CAPTURE-TIMELINE.txt"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "the stderr of a start-time read that failed is kept as the diagnosis" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-worker-a-11111"
|
||||
kubectl_timeline_rc=1
|
||||
kubectl_timeline_rows=
|
||||
kubectl_timeline_stderr='error: the server could not find the requested resource'
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=console-timeline-err
|
||||
|
||||
run_capture
|
||||
|
||||
# The other direction: on a failed read that message IS the diagnosis, and
|
||||
# dropping it leaves a note saying the read failed with nothing saying why.
|
||||
# The note has to name the file, or the evidence sits in a directory the
|
||||
# reader has no reason to open.
|
||||
dir="$COZY_REPORT_DIR/snapshots/console-timeline-err/tenant-serial-console"
|
||||
assert_file_contains 'could not find the requested resource' "$dir/CAPTURE-TIMELINE-error.log"
|
||||
[ ! -f "$dir/CAPTURE-TIMELINE-warnings.txt" ]
|
||||
assert_file_contains 'CAPTURE-TIMELINE-error.log' "$dir/CAPTURE-TIMELINE.txt"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "a start-time read that failed without a word does not point at a missing file" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-worker-a-11111"
|
||||
kubectl_timeline_rc=124
|
||||
kubectl_timeline_rows=
|
||||
kubectl_timeline_stderr=
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=console-timeline-silent
|
||||
|
||||
run_capture
|
||||
|
||||
# timeout kills the child without a word, so this read can fail having written
|
||||
# to neither stream. Naming the error log unconditionally would then send the
|
||||
# reader after a file that was never created, which is the same trap the
|
||||
# per-Pod notes above are written to avoid.
|
||||
dir="$COZY_REPORT_DIR/snapshots/console-timeline-silent/tenant-serial-console"
|
||||
[ ! -f "$dir/CAPTURE-TIMELINE-error.log" ]
|
||||
assert_file_contains 'gave no reason on either stream' "$dir/CAPTURE-TIMELINE.txt"
|
||||
assert_file_lacks_pattern 'reason it gave is in' "$dir/CAPTURE-TIMELINE.txt"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "the console container's start is asked for in both status lists" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-worker-a-11111"
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=console-timeline-lists
|
||||
|
||||
run_capture
|
||||
|
||||
# KubeVirt runs guest-console-log as an init container, so its runtime state
|
||||
# lives under initContainerStatuses. Asking only containerStatuses returns
|
||||
# empty for a container that started perfectly well, and an empty start time
|
||||
# here is supposed to mean the container never ran -- the one reading this
|
||||
# field exists to support. The attach check reads both spec lists for the
|
||||
# same reason; a missing key costs an empty string, so naming both is free.
|
||||
assert_file_contains 'initContainerStatuses[?(@.name=="guest-console-log")]' "$kubectl_calls"
|
||||
assert_file_contains 'containerStatuses[?(@.name=="compute")]' "$kubectl_calls"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "a run near its operation ceiling declines the baseline instead of being killed collecting it" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
# The capture costs real wall clock and runs after everything the suite
|
||||
# proves. Inside an operation with a fixed ceiling that makes it a way for a
|
||||
# green run to end red, which is the one thing a passing-path collector may
|
||||
# not do. Driven rather than grepped: the direction of the comparison IS the
|
||||
# safety property, and an inverted one runs the capture on exactly the runs
|
||||
# that cannot afford it while every structural check still passes.
|
||||
date_now=1000000000
|
||||
_COZY_RUN_STARTED_AT=$(( date_now - (COZY_OP_CEILING - COZY_GREEN_CAPTURE_RESERVE) - 1 ))
|
||||
rc=0
|
||||
( set +x; cozy_green_capture_has_room 'the baseline' ) >"$tmp/out" 2>&1 || rc=$?
|
||||
|
||||
[ "$rc" -eq 1 ]
|
||||
# And the decline is spoken. A collector that stops running silently leaves a
|
||||
# green run that looks exactly like one where the baseline was collected and
|
||||
# came back empty, which is the reading every note in this file exists to
|
||||
# prevent.
|
||||
assert_file_contains 'not collected' "$tmp/out"
|
||||
assert_file_contains 'the baseline' "$tmp/out"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "a run with the operation's room to spare collects the baseline" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
# The other direction, and the one an inverted comparison breaks silently: a
|
||||
# gate that declines a run with forty minutes left costs the baseline on every
|
||||
# healthy run, and the only symptom is a diagnostic that stopped appearing.
|
||||
date_now=1000000000
|
||||
_COZY_RUN_STARTED_AT=$(( date_now - 60 ))
|
||||
rc=0
|
||||
( set +x; cozy_green_capture_has_room 'the baseline' ) >"$tmp/out" 2>&1 || rc=$?
|
||||
|
||||
[ "$rc" -eq 0 ]
|
||||
assert_file_lacks_pattern 'not collected' "$tmp/out"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "a run whose start was never stamped declines rather than dying on the arithmetic" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
# The stamp is set by run_kubernetes_test, which no unit test invokes, so
|
||||
# nothing else here would notice it being deleted. Under the `set -eu` the
|
||||
# chainsaw script runs with, an unbound name inside the arithmetic aborts the
|
||||
# whole function -- ending a passing run red, which is the outcome this gate
|
||||
# exists to prevent. Declared zero at file scope, it fails closed instead.
|
||||
date_now=1000000000
|
||||
rc=0
|
||||
( set -u; set +x; cozy_green_capture_has_room 'the baseline' ) >"$tmp/out" 2>&1 || rc=$?
|
||||
|
||||
[ "$rc" -eq 1 ]
|
||||
assert_file_contains 'not collected' "$tmp/out"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "the passing path decides through the gate rather than around it" {
|
||||
lib=hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
# The behavioural tests above cover the predicate. Its wiring is what they
|
||||
# cannot reach: run_kubernetes_test is not callable from a unit test, so the
|
||||
# stamp it takes and the gate it calls are only assertable as source. Both
|
||||
# halves fail the same silent way -- a correct predicate nothing calls
|
||||
# protects nothing, and a predicate called without the stamp reads the whole
|
||||
# epoch as elapsed and declines the baseline on every run forever.
|
||||
stamp=$(grep -n '^ _COZY_RUN_STARTED_AT=\$(date +%s)$' "$lib" | head -n 1 | cut -d: -f1)
|
||||
gate=$(grep -n 'cozy_green_capture_has_room ' "$lib" | tail -n 1 | cut -d: -f1)
|
||||
green=$(grep -n "cozy_capture_tenant_serial_console 'the suite passed" "$lib" | head -n 1 | cut -d: -f1)
|
||||
for v in stamp gate green; do
|
||||
eval "n=\$$v"
|
||||
if [ -z "$n" ]; then
|
||||
echo "expected to locate $v in $lib" >&2
|
||||
return 1
|
||||
fi
|
||||
done
|
||||
# Inside the function whose elapsed time it measures, not at file scope: taken
|
||||
# once when the library is sourced, it would time the sourcing rather than the
|
||||
# run, and every suite after the first would read as already over its ceiling.
|
||||
fn=$(grep -n '^run_kubernetes_test() {$' "$lib" | head -n 1 | cut -d: -f1)
|
||||
if [ -z "$fn" ] || [ "$stamp" -le "$fn" ]; then
|
||||
echo "the run's start stamp (line $stamp) must be taken inside run_kubernetes_test (line $fn)" >&2
|
||||
return 1
|
||||
fi
|
||||
if [ "$stamp" -ge "$gate" ] || [ "$gate" -ge "$green" ]; then
|
||||
echo "expected the stamp ($stamp) before the gate ($gate) before the capture ($green)" >&2
|
||||
return 1
|
||||
fi
|
||||
}
|
||||
|
||||
@test "the operation ceiling the reserve is measured against is the one the suites give" {
|
||||
lib=hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
# A reserve is only meaningful against the right ceiling. This number is a
|
||||
# restatement of one that lives in the suite files, so it is read from both
|
||||
# sides rather than trusted: a suite that raises or lowers its `timeout:`
|
||||
# otherwise leaves the reserve protecting a ceiling that moved, and the
|
||||
# decline either stops firing when it should or starts firing when it should
|
||||
# not.
|
||||
ceiling=$(grep -oE '^COZY_OP_CEILING=[0-9]+' "$lib" | head -n 1 | sed -E 's/.*=//')
|
||||
reserve=$(grep -oE '^COZY_GREEN_CAPTURE_RESERVE=[0-9]+' "$lib" | head -n 1 | sed -E 's/.*=//')
|
||||
for v in ceiling reserve; 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 f in hack/e2e-chainsaw/kubernetes-latest/chainsaw-test.yaml \
|
||||
hack/e2e-chainsaw/kubernetes-previous/chainsaw-test.yaml; do
|
||||
# The first `timeout:` in each file is the bringup op's, which is the one
|
||||
# this whole helper runs inside; the teardown step below it has its own.
|
||||
minutes=$(grep -oE '^ *timeout: [0-9]+m$' "$f" | head -n 1 | grep -oE '[0-9]+')
|
||||
if [ -z "$minutes" ]; then
|
||||
echo "expected to read the operation timeout from $f" >&2
|
||||
return 1
|
||||
fi
|
||||
if [ "$((minutes * 60))" -ne "$ceiling" ]; then
|
||||
echo "$f gives the operation ${minutes}m but the reserve is measured against ${ceiling}s" >&2
|
||||
return 1
|
||||
fi
|
||||
done
|
||||
# And the reserve has to leave room for the capture it is reserving for, or it
|
||||
# protects nothing: the walk it admits would still run past the ceiling.
|
||||
if [ "$reserve" -lt 210 ]; then
|
||||
echo "the reserve ${reserve}s is under the 210s the capture can cost at this caller's cap" >&2
|
||||
return 1
|
||||
fi
|
||||
}
|
||||
|
||||
@test "the e2e tenant node group asks KubeVirt for the guest console log" {
|
||||
# Anchored to a bare six-space-indented key so a comment or a prose mention
|
||||
# of the field cannot stand in for the setting itself. It does not prove the
|
||||
|
||||
Reference in new issue
Block a user