Repository navigation
E2E: tenant worker bring-up misses the node-Ready budget with zero Nodes registered — survived #3455's fsync fix and the 12m→18m raise #3513
Description
Activity
Fresh evidence from the
cozyreportof a recent run (run 30940776005,kubernetes-latest, both host and tenantcrust-gathersnapshots) lets me rule out several standing outside-guest theories and quantify the in-guest window this issue is about.Timeline (kubernetes-latest, from the host snapshot):
Time (UTC) Event 08:34:40 Tenant apiserver (Kamaji Deployment) created and rolled exactly once (rev1 to rev2); not flapping thereafter 08:34:51 talos-csr-signersidecar listening08:35 to 08:36 Workers pull the Talos image from talos-image-cachequickly (206/200, no stalls)08:37:50 Worker VMI Running(...-828wgon srv1,...-x7l67on srv3, spread across nodes)08:37 to 08:53 Machines BootstrapReady=True,NodeHealthy=False; no Node ever registers08:51:56 MHC nodeStartupTimeout: 10m0strips; remediation blocked bymaxUnhealthy: 50%(total 2, unhealthy 2)08:53:00 First and only kubelet CSR signed ( ...-828wg); the second worker never requests oneThe gap from VMI
Running(08:37:50) to the kubelet CSR (08:53:00) is ~15 minutes, entirely inside the guest, and the Node still never reaches Ready within the 18m budget. This is exactly the unobserved window named here.What this run rules out (every outside-guest layer is healthy):
- kube-ovn / OVN is not the cause. The
default logical switch is not founderrors and the ovn-centralbackup raft headerlines are startup transients confined to a 185ms burst at 06:53:13; the leaderkube-ovn-controllerthen ran stably from 06:53 to 08:53. By the time workers boot (08:37) the network is healthy. (Flagging this because an earlier internal analysis had pinned kube-ovn; this snapshot does not support it.) - The tenant apiserver did not flap. One rollout at creation (08:34:40), stable after.
- The path to the signer works. The CSR at 08:53:00 succeeded, so DNS, routing and the apiserver Service VIP are all functional.
- Image delivery is fast and bootstrap config was delivered (
BootstrapReady=True).
The only bottleneck left is the guest boot itself: roughly 15 minutes to reach the CSR versus a normal 2 to 3. That magnitude is consistent with CPU/IO starvation of the worker VMs under concurrent management-cluster load, which is why only the two full-cluster worker suites fail while the control-plane-only kubernetes suites pass, and why no outer timeout has helped: none of them outruns an in-guest stall. #3455's move to an 18m budget cannot help for the same reason.
Two takeaways:
- The remaining unknown is strictly in-guest (dmesg / kubelet / apid), which is precisely what fix(e2e): capture Talos logs for tenant worker join failures #3548 captures. This run confirms there is nothing left to find outside the guest.
- Independently of the root cause,
MachineHealthCheck.nodeStartupTimeout(10m) is shorter than the observed boot (~15m), so CAPI marks the node unhealthy before it can register. Even a partial guest speed-up will keep tripping this; it is worth raising above the worst-case boot time regardless.
- kube-ovn / OVN is not the cause. The
- added 10 commits that reference this issue
on Aug 6, 2026 64 remaining items
Environment probe result. Two July-era main trees were replayed today (2026-08-18) to separate the tree from the environment: 2823b76, which had a green full-suite run on 2026-07-24 and a red one on 2026-07-28 on the identical tree, and a80f134 from the middle of that window. Both replays failed, and they attribute differently.
The 2823b76 replay (run 32157688662) reproduces this issue's mechanism end to end: both tenant Kubernetes suites red, MachineHealthCheck RemediationRestricted with "unhealthy: 2, maxUnhealthy: 50%" on both the previous-version and latest-version MachineDeployments, and a third machine's disk-system importer stuck waiting for its scratch PVC, which is the pile-on documented earlier in this thread. The a80f134 replay (run 32157692709) failed as the install-phase flake tracked in #3851 instead and is not a node-join witness.
A tree that passed on July 24 failing today with this issue's exact signature means the outcome is set by the environment, not by the tree, so a bisect over main cannot land on a culprit commit. The replay also shows the old fixed budgets losing to the pile-on (remediation blocked at maxUnhealthy 50% while the scale-up machine imports its root disk on the degraded host); the widened and configurable budgets from #3898, #3899 and #3901 target exactly that failure path and the next wave of runs on current main will show whether joins complete inside honest budgets.
The last instrument for this investigation landed in #3919: a fixed-work canary that runs two bounded workloads on the runner VM, an integer loop and a streaming write, on both sides of the node-join wait, on the failing and the passing path alike. Every reading collected so far measures time or events against whatever workload happened to run; this one carries its own unit of work, so it gives an absolute answer to the question the earlier data could not settle: whether the machine itself was getting less work done per tick, and whether the slowdown began inside the join window or was already there going into it. The two arms react differently to compute starvation and to pressure on the shared cache and memory controller, which is the remaining fork in this issue. From here on, green runs leave a baseline in every report and red runs carry the comparison, so the widened join budgets from #3898, #3899 and #3901 can be judged against runs whose environment state is recorded instead of guessed.
First harvest from the fixed-work canary added in #3919, and it answers the question it was built for. Run 32350477760 is a red node-join run from today's degraded window, and the runner-layer canary read healthy there on both samples and both arms: the integer loop at 15-18M iterations per second and the streaming write at 12.6-14.4 GiB per second, within a few percent of the green-run baseline taken the same hour on run 32350626034 (16-17M and 13.0-13.7). In the same red run, both tenant workers' serial consoles show initramfs unpacking taking 88 and 84 seconds against the 13-15 second green baseline. A healthy runner core and guests running six to seven times slow, at the same moment, in one run: pressure on the shared cache or the memory controller at the runner's level would have depressed the canary's streaming arm, and it did not move. That resolves the remaining fork toward the nested virtualisation path itself: the cost sits between the runner's KVM and the nested guests, consistent with the exit-storm signature recorded earlier in this thread (267-273k exits per second with tlb_flush at about 2.66x nested_run), not in resource pressure the runner can feel.
Separately, the widened budgets from #3898, #3899 and #3901 behaved as designed on today's reds, run 32348997754 among them: two machines, quietly Provisioned, no premature remediation, no third machine, no pile-on. The guests were left alone to boot slowly, the consoles show Talos progressing rather than wedged (an initialize sequence completing in 4m58s), and the binding constraint is now the suite's own 18m join deadline rather than any product timer.
Cause is outside this repo. cncf/automation#544 merged on 07-24 changed
--shape-ocpusto mean vCPUs and divide by 2 before the OCI API sees it, but the scale set manifests still pass the old number, sooracle-vm-32cpu-128gb-x86-64gives 16 OCPUs / 32 vCPUs now and gave 32 OCPUs / 64 vCPUs before. f1de260 rolled it to the runners the same day, and our nightly was green 07-21 to 07-24 and red 07-25 to 07-29. Filed as cncf/automation#601, asking for--shape-ocpus=64.0back on this class. The same PR also cut the boot volume from 600 GB at 120 VPU to 300 GB at 30 VPU.The runner is not idle, it just cannot report that it isn't. The 24 sandbox guest vCPU threads in
sandbox-qemu-thread-cpueach get 0.61 to 0.79 of a core and sum to 15.3 to 16.3 cores on a 16 core machine, which is the fair share of 16 cores split 24 ways./proc/statreads around 50% idle with steal at 0.01% because those 24 threads spread over 32 SMT siblings, so every logical cpu sits half busy. Green and red both, so this is the regime and not the discriminator. Careful reading that file,utimeis index 10 of the fields afterstate, and off by one there gives 3.5 cores and looks like an idle box.The exit storm reading does not hold up against a baseline. Run 32350626034 passed and 32350477760 failed, same hour, same scale set, both carrying the full instrument set. Green has more exits, 333-342k/s against 259-262k/s, and every nested counter is higher on the green path: nested_run 9.8-10.4k/s against 2.2-2.3k/s, tlb_flush 29k against 5-6k, pf_taken 7.8-8.0k against 0.7-0.9k, and tlb_flush/nested_run 2.79-3.01 against 2.34-2.55. Nothing on the red path is amplified, all of it scales down with the progress the guest fails to make.
Two things to retract. E4 / 7J13 / us-ashburn-1 does not cluster with failure, the red run above was EPYC 7763 and the green one 7J13, both E4.Flex in us-ashburn-1. And hardware virtualisation is fine at every level: red guest consoles print
Hypervisor detected: KVMand switch clocksource to kvm-clock, we never setuseEmulationso a missing/dev/kvmwould fail the VMI rather than slow it, and nested_run is non zero on exactly the two sandbox VMs that host workers.One note on 08ac063. It moved e2e off the 24cpu label because 24 guest vCPUs on a 24 vCPU host left no headroom, but the labels over delivered 2x back then, so it actually moved from 48 to 64 vCPUs. #544 made the labels literally true, which left us sitting on the configuration that commit calculated and never actually ran.
- added 6 commits that reference this issue
on Aug 26, 2026 closing this as completed by reducing nested virtualization in e2e
- added a commit that references this issue
on Sep 24, 2026
Status 2026-08-15
The framing below is out of date, and reading this issue top-down sends you at work that is already done. Point 1 of "What would close this" shipped in 80152b1 on 2026-08-05, and the analysis it made possible lives in the comments rather than here. Read #3513 (comment) and #3513 (comment) before anything below.
One of this issue's hypotheses is closed by measurement and one is not, and the difference is which instrument was used. A cold ghcr.io fetch is not in the path: #3768 warms both kubelet tags at install time, and on run 31582632048 the mirror answered manifests in 5.7 to 25.4ms and blobs in 4.1 to 8.7s. CPU is less settled than it looks. The #3723 collector on nightly 31662393360 records 4.8 to 13.9 seconds of throttled time on container
computeat a quota/period of 1.0, which refutes CFS bandwidth throttling and nothing wider:u1.mediumgives the guest one vCPU,cpuAllocationRatio: 10inpackages/core/platform/values.yamlturns that into a 100m request, and KubeVirt's AutoResourceLimitsGate sets the limit to 1 CPU because the tenant namespace carries alimits.cpuquota. The Pod is Burstable with a tenfold gap between request and limit, so under node contention the guest is entitled to a tenth of a core, and run-queue waiting at that level never shows up in a throttle counter. One more thing before anyone reads those files: the collector filters on namespace andpod="virt-launcher-and never pinscontainer="compute", so an unfiltered read mixes theguest-console-logsidecar into the same table.What is left is three separate failures behind one error line, and they need to stop being triaged as one.
kubernetes-previous: kubelet never leaves PreFunc because its image trickles, 7 MiB of 61 in 2m40s. Undecided whether the pull restarts and discards progress or the channel is simply narrow, and the guest cannot tell you, it logspulling image ...: starting...five times before the first percentage appears. fix(e2e): capture both ends of the worker byte path on node-join failure #3804 adds the host-sidecontainer_network_*counters on the virt-launcher Pod that separate the two, and it is approved but not merged. That PR is the next step here.kubernetes-latest: kubelet parked onWaiting for service "cri" to be "up", not a singlepulling imageline in its dmesg, capture ending onservice[cri]health check DeadlineExceeded. Mechanism not established.Ready=Falseoncni plugin not initialized. That is E2Ekubernetes-previousfails consistently: Cilium install times out inside tenant cluster on v1.34.9 nodes #3229's fingerprint and does not belong here.Two diagnostic gaps stay open whichever variant you chase.
talosctl logs kubeletreturnslog "kubelet" was not registeredon every worker, so the service log is never collected at all, and #3804'stalosctl servicesread is what answers in its place. And one worker per run tends to yield nothing, withdial tcp <ip>:50000: connect: connection refusedwhere its capture should be.Still true from the original writeup: do not raise the 18m budget. 12m to 18m changed nothing, and Talos PullTimeout is 20m against that 18m, so the suite kills the pull two minutes before Talos would report its own verdict and the artifacts never hold a pull error.
Everything below is the original 2026-08-03 writeup, kept as the evidence trail.
Summary
Both tenant-Kubernetes e2e suites (
kubernetes-latestandkubernetes-previous) fail the node-Ready budget with zero Nodes ever registering in the tenant cluster, while the worker VMs are healthy at the KubeVirt layer and the OS disk import finishes in seconds. The time is lost entirely inside the guest, between "VMI Running with an imported disk" and "Talos requests its apid certificate".This failure mode has now been attacked four times under three different theories (#3159, #3229, #3455, #3294) and is still open. Most importantly it survived #3455, which both removed the guest-fsync stall (
cache=unsafe) and raised the node-Ready budget from 12m to 18m: the identical fingerprint #3455 documents as its motivating case has recurred at the new 18m deadline. This issue exists to consolidate the evidence in one place and to name the one diagnostic that has never been collected.Fingerprint
Reference run: https://github.com/cozystack/cozystack/actions/runs/30609726298 (job
E2E Tests, stepRun E2E tests), 2026-07-31. 41 suites passed, 2 failed.Both fail identically:
Queried against the
crust-gathersnapshots the run uploaded incozyreport.tgz:The infrastructure layer is healthy, and CAPI never observes a node either:
Where the time goes
Timeline for
kubernetes-latest, from the host snapshot and thetalos-csr-signersidecar log:kube-apiserverstartsRunningtalos-csr-signersigns a cert - for…-dc8slonlySo one worker took 12m49s from
Runningto issuing its apid CSR, and the second never issued one at all. The tenantkube-apiserverlog contains no kubelet contact whatsoever - grepping it forkubelet/node/csrreturns only its own startup lines.The OS disk import is not the bottleneck. From the
talos-image-cacheaccess log:Import completed in roughly 24 seconds, and the suite's own preflight agrees:
talos-image-cache mirror reachable from tenant namespace (byte-range 206 verified).Host resource state does not show global starvation either.
freeon the sandbox reports 128805 MB total with 52268 MB available, and across all three sandbox nodes there are exactly two OOM kills, both memcg-scoped and neither in the worker path (task=mariadbdon srv1 at 08:11:22,task=kube-apiserveron srv3 at 08:46:51). Nohung task,soft lockup, or host-level OOM in any node dmesg.This is not #3229
#3229 is currently the de-facto tracker for this, but both its title and its diagnosis no longer match what the artifacts show, and triaging by that title sends people to the wrong layer:
previousfails consistently,latestpassesNotReadywithcni plugin not initializedcilium-operatorisPendingfor lack of any node to schedule onThe stuck
<release>-ciliumHelmRelease that #3229 leads with is a symptom of an empty cluster, not a cause. Recommend retitling/refocusing #3229 onto this issue or closing it in favour of this one.Prior attempts, and why the newest evidence outlives them
cilium-agentlogcache=writeback→ guest fsync storm → management etcd Raft stalls → operators lose leader electioncache=unsafeon all three guest drives, plus node-Ready budget 12m → 18mtalos-image-cacheworkaround#3455 was active in the reference run -
cache=unsafeappears three times in the job log and the failure message readswithin 18m, the raised value. Its own diff comment describes the motivating case as:That is line-for-line the reference run, at 18m instead of 12m. Removing the fsync stall and adding six minutes of margin moved the deadline without closing the failure, which argues the remaining cost is not the host I/O path and not import bandwidth - the import here took 24 seconds - but something in guest bring-up itself.
What is blocking a root cause
Every investigation so far has stopped at the same wall. The suite's own diagnostics say it outright:
Nothing in the host snapshot, the tenant snapshot, the image-cache log, the sandbox dmesg, or the tenant apiserver log covers the window between VMI
Runningand the apid CSR - which is exactly where the 13 minutes go. All four attempts above were therefore inferred from outside the guest. This is the concrete instance of #3368 ("35% of red runs are undiagnosable").What would close this
talosctl dmesgandtalosctl logs kubeletfrom a worker that misses the budget. This needs a tenanttalosconfigon the runner, which the harness does not currently produce - wiring that into thecatchblock is the prerequisite, and it is the single highest-value change here.Notes
kubernetes-latestwith the same chainsaw assertion($error == null), but for a different underlying reason - there the nodes joined and the suite failed later onhelmreleases/kubernetes-test-latest-version-csitiming out. Worth noting so the generic assertion text is not treated as a single signature.