Skip to content

Commit dda339f

Browse files
authored
fix(e2e): keep a failed image-mirror lookup from pinning the public factory (#3677)
## What this PR does The tenant Kubernetes e2e suites decide once whether worker image pulls go to the in-cluster Talos mirror or to the public Image Factory, and that decision came from a plain `kubectl get deploy talos-image-cache`. A plain `get` exits non-zero for a connection refused, an Unauthorized and a real absence alike, so any blip during that one call read as "no mirror", and the answer went straight into the decision file every later tenant test reads. One unlucky moment sent every worker in the run to the public factory over live egress, which is the dependency the mirror exists to remove, and nothing in the log said so. The run went ahead against the flaky thing and the failures read as environment noise. The lookup now asks with `--ignore-not-found -o name`. A real absence answers exit 0 with no output, which leaves a non-zero exit meaning only that the question failed, and the helper re-asks a couple of times before giving up. Only the empty answer turns the suite toward the public factory. An unanswered lookup warns, falls back for its own caller alone, and is deliberately not cached, so the next tenant test asks again instead of inheriting a guess. The warning has to be backed by something, and kubectl's stderr alone is not enough. When the wall-clock bound kills an attempt, neither the bound nor the SIGTERMed kubectl writes a word, and that stall is precisely the failure the re-ask was written against, so a warning that sent the reader to kubectl's message would be pointing at an empty stretch of log exactly when the lookup mattered. The lookup therefore names the last attempt's exit status before giving up, in the vocabulary the diagnostic reads already use for 124 and 137, and kubectl's own text stays on stderr for the cases where there is any. Each attempt is bounded twice, and the two bounds are deliberately not equal: `timeout -k 5 40` around `--request-timeout=30s`. kubectl defaults the request timeout to 0, so a connection that establishes and then stalls has no deadline at all, and the flag on its own is not a wall-clock bound either, because kubectl retries discovery several times before it gives up. Re-asking an unbounded call three times would have multiplied a hang instead of riding out a blip. The ten seconds between the two are load-bearing, and I only found out why by measuring rather than reasoning. Driven against a stub apiserver the three failure modes are not alike: a refused port answers in under a second and names the refusal, one that completes TCP but stalls mid-TLS hits kubectl's own handshake deadline and still produces text despite being killed, and a blackholed address (SYN dropped, no RST, which is what a wedged node or a netpol looks like) produces nothing at all until some deadline expires. That last mode is the one the headroom buys back. With both bounds at the same value the expiry that arrives first is always the wall-clock kill, so the blackhole case ends as a bare exit 124; with the wrapper ten seconds above, the request deadline ends the attempt and kubectl says what happened, and the wrapper stays as the backstop for a client that overruns its own deadline. Controlled A/B, same target and same inner bound, only the outer differs: 30 over 30 gives exit 124 and zero bytes, 40 over 30 gives exit 1 at the thirty second mark and a message naming the cause. The cost is ten more seconds per attempt on a path where the apiserver is already unreachable, inside a 50m op. Worth stating separately, because it is a different question with a different answer: before this change the inner flag was not doing anything at all. `--request-timeout=30s` sat under a `timeout` of the same 30 seconds, and across all three measured modes it never once fired. The refused case never reached it, the TLS stall was ended by kubectl's own shorter handshake deadline, and the blackhole was ended by the wall-clock kill landing at the same instant. So the flag was decoration, and the comment above it claimed otherwise. That is a separate defect from the lost diagnostics, and it is fixed by the same separation rather than by adding anything. Where `timeout` is not installed the read runs unwrapped instead of through it. Its exit 127 would otherwise count as an attempt that did not answer, three times over, so a missing local binary would pin the whole suite to the public factory while every message blamed the apiserver. `talos_image_cache_diagnose` asks the same question on the node-join failure path, and #3676 landed its own three-way gate there while this branch was open. The two stay separate rather than sharing this helper. That one runs under a phase budget where re-asking spends what the tenant snapshot behind it needs, so it answers on a single attempt; this one runs on the happy path, where a re-ask costs a suite nothing and buys back the mirror. This branch leaves that gate as it was merged. Unit tests put a throwaway `kubectl` and `timeout` on PATH and drive all three outcomes, the re-ask, the caching rule, the `timeout`-absent path and the killed-attempt path where nothing but the lookup itself can explain the failure: `hack/cozytest.sh hack/talos-image-cache_test.bats`. The stubs are files rather than shell functions because an external `timeout` binary execs a real file and would never see a shell override. The re-ask is a retry loop, which `docs/agents/e2e-testing.md` restricts. It falls under the exemption there rather than the prohibition: what is retried is a network read with no product or test logic under it, and the deterministic steps the rule protects are untouched. This relates to #3668 and closes the first door only. The decision is cached once at the end of the function regardless of which inner check produced the negative answer, and inside the "mirror is present" branch the `rollout status` wait and the three reads in `_talos_image_cache_reachable_from_tenant` still conflate "the mirror does not work" with "the probe could not be run", with the same suite-wide effect one layer down. The issue's own status comment says it stays open after this change, so there is no closing keyword here. Three weaknesses this PR does not remove, named because each is a real thing a later reader will hit. The `absent` case in `resolve_talos_image_factory_url` is reached by `else` fall-through rather than by matching the token, so a fourth state added to the helper later would land in the branch that turns the suite toward the public factory rather than in the safe one; a test pins the `present` token against exactly that drift, but the shape stays fall-through. The lookup's own `30` and `5` are literals while the diagnostic reads next door run off a validated, overridable pair, and that is deliberate rather than an oversight: those knobs are named and documented for the dump budget, so wiring the lookup to them would let a test that turns the dumps down silently change which image factory a whole suite pulls from. And `_TALOS_IMAGE_CACHE_QUERY_TRIES` is the one knob in the file without that validation. A non-numeric value spins the loop forever rather than failing: the comparison sits in an `if` condition, so `set -e` is exempt, the branch is simply never taken, and the job burns to its ceiling with no output. Nothing outside the tests sets it, which is why it is here and not in the diff. Worth recording for whoever does fix it: the obvious remedy, reusing this file's own `_talos_image_cache_seconds`, does not work where the knob is assigned, because the validator is defined a hundred lines further down and the assignment runs at source time. The call resolves to nothing, the substitution yields an empty string, and an empty bound spins the same loop. A real fix has to move the definition up or validate inside the function at call time. ### Screenshots Not a UI change. ### Downstream repositories Walked the trigger map against the diff. It touches `hack/e2e-chainsaw/_lib/talos-image-cache.sh` and `hack/talos-image-cache_test.bats` and nothing else: no file under `hack/` is moved or renamed, no make target changes behaviour, and no package, chart, CRD or values key is involved. The `cozystack/ccp` entry is the closest one and it does not fire. - [x] No downstream repository is affected by this change ### Release note ```release-note fix(e2e): a single failed apiserver lookup no longer sends a whole e2e run to the public Talos Image Factory ```
2 parents 048088b + 5400f16 commit dda339f

2 files changed

Lines changed: 377 additions & 10 deletions

File tree

‎hack/e2e-chainsaw/_lib/talos-image-cache.sh‎

Lines changed: 110 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -144,18 +144,124 @@ _talos_image_cache_reachable_from_tenant() {
144144
_talos_image_cache_probe_succeeded "$out"
145145
}
146146

147+
# _talos_image_cache_deploy_state: answer "is the mirror Deployment there?" as
148+
# exactly one of present, absent or unknown.
149+
#
150+
# --ignore-not-found is what makes a three-way answer possible: a genuine absence
151+
# becomes exit 0 with no output, which leaves a non-zero exit meaning only "the
152+
# question was never answered" — connection refused, Unauthorized, timed out.
153+
# A plain `get` collapses those two into one exit code, and the caller below then
154+
# reads a blip as an absence, caches it, and sends every tenant worker in the
155+
# suite to the public factory over the live egress the mirror exists to avoid.
156+
# Same idiom as the teardown poll in hack/e2e-chainsaw/_lib/etcd-cleanup.sh.
157+
#
158+
# talos_image_cache_diagnose asks the same question and answers it its own way,
159+
# and the two are separate on purpose. That one runs on the node-join failure
160+
# path under a phase budget, where re-asking spends what the crust-gather
161+
# snapshot after it needs, and it gives up after one attempt. This one runs on
162+
# the happy path, where a re-ask costs a suite nothing and buys it the mirror.
163+
#
164+
# The re-ask is small, and each attempt has to be bounded twice over for the
165+
# re-ask to be worth anything. kubectl's --request-timeout defaults to 0 — no
166+
# deadline on the request at all — and the case this loop exists for is a
167+
# connection that establishes and then stalls, which client-go's dial timeout
168+
# does not bound. The flag on its own is still not a wall-clock bound: against
169+
# an unreachable apiserver kubectl retries discovery several times before it
170+
# gives up, so a call carrying only the flag costs a multiple of it, which
171+
# hack/e2e-chainsaw/_lib/pod-label-census.sh measured and sized its caller's op
172+
# timeout around. Asking three times would inherit that multiple, inside a
173+
# Chainsaw op the rest of the tenant test has to fit in. So each attempt takes
174+
# both bounds, the pairing the reads in run-kubernetes.sh use and explain beside
175+
# its pod list: --request-timeout bounds the HTTP request, timeout bounds the
176+
# client retrying against a wedged apiserver. A kill by timeout exits non-zero
177+
# and is simply another attempt that did not answer. Past that, an apiserver
178+
# that is down does not become reachable by asking longer, and a run whose
179+
# apiserver is down has bigger problems than which factory it pulls from. A
180+
# real absence answers on the first try and waits for nothing.
181+
#
182+
# The wrapper is skipped rather than depended on when `timeout` is not installed,
183+
# for the reason _talos_image_cache_bounded_read gives below and one more that is
184+
# specific to a loop: its exit 127 would otherwise count as an attempt that did
185+
# not answer, three times over, and a missing local binary would pin the whole
186+
# suite to the public factory while every message blamed the apiserver.
187+
#
188+
# The outer bound sits ABOVE the inner one rather than level with it, and that
189+
# gap is the whole reason kubectl ever gets to explain itself. Measured against a
190+
# stub apiserver, the three ways this call fails are not alike. A refused port
191+
# answers in under a second and names the refusal. One that completes TCP but
192+
# stalls in TLS gets kubectl's own handshake deadline, which is shorter than
193+
# either bound and fires twice inside the window, so there is text even though
194+
# the wrapper ends up killing the call. A blackholed address — SYN dropped, no
195+
# RST, which is what a wedged node or a netpol looks like — produces nothing at
196+
# all until some deadline expires, and with the two bounds equal the expiry that
197+
# arrives is the wall-clock kill, at the same instant as the request deadline it
198+
# beats to it. `--request-timeout` then cannot fire in any of the three, which
199+
# makes it decoration. Ten seconds of headroom hands that case back to kubectl:
200+
# the request deadline ends the attempt and says why, and the wrapper stays as
201+
# the backstop for a client that overruns its own deadline. The cost is ten more
202+
# seconds per attempt on a path where the apiserver is already unreachable,
203+
# against a 50m op.
204+
#
205+
# kubectl's stderr is therefore deliberately not swallowed: it is the only thing
206+
# that separates refused from unauthorized from stalled, and suppressing it would
207+
# replace one silent failure with another. It is still not guaranteed — a kill
208+
# can always land before the client has said anything — so the last attempt's
209+
# exit status is named too, in the vocabulary the diagnostic reads below use for
210+
# 124 and 137. Between the two the caller's warning always has something real to
211+
# point at.
212+
_TALOS_IMAGE_CACHE_QUERY_TRIES="${_TALOS_IMAGE_CACHE_QUERY_TRIES:-3}"
213+
_TALOS_IMAGE_CACHE_QUERY_DELAY="${_TALOS_IMAGE_CACHE_QUERY_DELAY:-5}"
214+
_talos_image_cache_deploy_state() {
215+
local out rc try=1
216+
while :; do
217+
rc=0
218+
if command -v timeout >/dev/null 2>&1; then
219+
out=$(timeout -k 5 40 kubectl -n kube-system get deploy talos-image-cache \
220+
--request-timeout=30s --ignore-not-found -o name) || rc=$?
221+
else
222+
out=$(kubectl -n kube-system get deploy talos-image-cache \
223+
--request-timeout=30s --ignore-not-found -o name) || rc=$?
224+
fi
225+
if [ "$rc" -eq 0 ]; then
226+
if [ -n "$out" ]; then
227+
printf 'present'
228+
else
229+
printf 'absent'
230+
fi
231+
return 0
232+
fi
233+
if [ "$try" -ge "$_TALOS_IMAGE_CACHE_QUERY_TRIES" ]; then
234+
echo "WARNING: the talos-image-cache lookup gave up after ${_TALOS_IMAGE_CACHE_QUERY_TRIES} attempts; the last one exited ${rc} (124 = cut off at the wall-clock bound, 137 = SIGKILL after it, and both of those print nothing of their own; any other status is kubectl's, and its message is above)" >&2
235+
printf 'unknown'
236+
return 0
237+
fi
238+
try=$((try + 1))
239+
sleep "$_TALOS_IMAGE_CACHE_QUERY_DELAY"
240+
done
241+
}
242+
147243
# resolve_talos_image_factory_url: print the imageFactoryURL to use, or an empty
148-
# string to signal "use the chart default". The decision is resolved once (with a
244+
# string to signal "use the chart default". A decision that was actually reached
245+
# — the mirror is there, or it demonstrably is not — is taken once (with a
149246
# bounded wait for the mirror to finish seeding) and cached in a /tmp file that
150247
# persists across bats files (they all exec in the same sandbox container), so
151-
# only the first tenant Kubernetes test pays the readiness wait.
248+
# only the first tenant Kubernetes test pays the readiness wait. A lookup that
249+
# never got an answer decides nothing and caches nothing; the next tenant test
250+
# asks again.
152251
resolve_talos_image_factory_url() {
153252
if [ -f "$_TALOS_IMAGE_FACTORY_DECISION_FILE" ]; then
154253
cat "$_TALOS_IMAGE_FACTORY_DECISION_FILE"
155254
return 0
156255
fi
157-
local url=""
158-
if kubectl -n kube-system get deploy talos-image-cache >/dev/null 2>&1; then
256+
local url="" state
257+
state=$(_talos_image_cache_deploy_state)
258+
if [ "$state" = unknown ]; then
259+
# Nothing was established, so nothing is cached: this caller falls back for
260+
# itself and the next tenant test asks again.
261+
echo "WARNING: could not determine whether the talos-image-cache mirror is deployed (the lookup's own account of why is above) — this test falls back to public factory.talos.dev; nothing is cached, so the next tenant test asks again" >&2
262+
return 0
263+
fi
264+
if [ "$state" = present ]; then
159265
# Available only after the seed initContainer has fully fetched the image, so
160266
# this is the signal that the mirror is warm.
161267
if kubectl -n kube-system rollout status deploy/talos-image-cache --timeout=12m >/dev/null 2>&1; then

0 commit comments

Comments
 (0)