E2E: tenant worker bring-up misses the node-Ready budget with zero Nodes registered — survived #3455's fsync fix and the 12m→18m raise

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 compute at a quota/period of 1.0, which refutes CFS bandwidth throttling and nothing wider: u1.medium gives the guest one vCPU, cpuAllocationRatio: 10 in packages/core/platform/values.yaml turns that into a 100m request, and KubeVirt's AutoResourceLimitsGate sets the limit to 1 CPU because the tenant namespace carries a limits.cpu quota. 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 and pod="virt-launcher- and never pins container="compute", so an unfiltered read mixes the guest-console-log sidecar 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 logs pulling 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-side container_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 on Waiting for service "cri" to be "up", not a single pulling image line in its dmesg, capture ending on service[cri] health check DeadlineExceeded. Mechanism not established.
Node registers, then sits Ready=False on cni plugin not initialized. That is E2E kubernetes-previous fails 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 kubelet returns log "kubelet" was not registered on every worker, so the service log is never collected at all, and #3804's talosctl services read is what answers in its place. And one worker per run tends to yield nothing, with dial tcp <ip>:50000: connect: connection refused where 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-latest and kubernetes-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, step Run E2E tests), 2026-07-31. 41 suites passed, 2 failed.

--- FAIL: chainsaw (0.03s)
    --- FAIL: chainsaw/kubernetes-previous (1531.93s)
    --- FAIL: chainsaw/kubernetes-latest (1489.54s)
- Passed  tests 41
- Failed  tests 2

Both fail identically:

=== node-join failed: fewer than 2 tenant nodes Ready within 18m — diagnostics follow ===

Queried against the crust-gather snapshots the run uploaded in cozyreport.tgz:

$ kubectl --context tenantkubeconfig-test-previous-version get nodes
No resources found
$ kubectl --context tenantkubeconfig-test-latest-version get nodes
No resources found

$ kubectl --context tenantkubeconfig-test-latest-version get pods -A
NAMESPACE     NAME                               READY   STATUS    RESTARTS
cozy-cilium   cilium-operator-8658b7c645-bqddg   0/1     Pending   0

The infrastructure layer is healthy, and CAPI never observes a node either:

$ kubectl --context host -n tenant-test get vmi
NAME                                             PHASE     IP            NODENAME   READY
kubernetes-test-latest-version-md0-vmgs6-42prr   Running   10.244.1.92   srv3       True
kubernetes-test-latest-version-md0-vmgs6-dc8sl   Running   10.244.1.93   srv1       True

$ kubectl --context host -n tenant-test get machines
NAME                                             NODENAME   PHASE         VERSION
kubernetes-test-latest-version-md0-vmgs6-42prr              Provisioned   v1.35.6
kubernetes-test-latest-version-md0-vmgs6-dc8sl              Provisioned   v1.35.6

Where the time goes

Timeline for kubernetes-latest, from the host snapshot and the talos-csr-signer sidecar log:

Time	Event
08:50:28	tenant `kube-apiserver` starts
08:53:20 / 08:53:38	both worker VMIs reach `Running`
09:06:27	`talos-csr-signer` signs a cert - for `…-dc8sl` only
09:09:12	suite times out at 18m

So one worker took 12m49s from Running to issuing its apid CSR, and the second never issued one at all. The tenant kube-apiserver log contains no kubelet contact whatsoever - grepping it for kubelet/node/csr returns only its own startup lines.

The OS disk import is not the bottleneck. From the talos-image-cache access log:

08:18:00 10.244.1.47 "GET /image/ce4c9805…/v1.13.6/openstack-amd64.raw.xz HTTP/1.1" 200
08:18:01 10.244.1.47 … 206
08:18:24 10.244.1.49 … 206

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. free on 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=mariadbd on srv1 at 08:11:22, task=kube-apiserver on srv3 at 08:46:51). No hung 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:

#3229 says	This run shows
`previous` fails consistently, `latest` passes	both minors fail, same assertion, same run
Node registers, then goes `NotReady` with `cni plugin not initialized`	no node ever registers
Cilium 1.19.5 vs k8s 1.34.9 API surface is a candidate cause	Cilium is downstream - `cilium-operator` is `Pending` for lack of any node to schedule on

The stuck <release>-cilium HelmRelease 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

Attempt	Theory	Shipped	Status against this run
#3159 (merged 2026-07-01)	Previous tenant test had not vacated the sandbox; the next test's worker VMs schedule against still-reserved guest RAM	Bounded drain barrier for tenant VMs/VMIs/PVCs between kubernetes tests	In effect; did not prevent it
#3229 (open 2026-07-07)	Cilium/k8s-1.34 API delta, or slow kubelet image pull	none - blocked asking for a `cilium-agent` log	Diagnosis superseded, see above
#3455 (merged 2026-07-29)	QEMU `cache=writeback` → guest fsync storm → management etcd Raft stalls → operators lose leader election	`cache=unsafe` on all three guest drives, plus node-Ready budget 12m → 18m	In effect and still failing
#3294 (open)	Per-worker ~4 GiB CDI HTTP import races the in-sandbox image-cache across the kube-ovn/Cilium datapath	Golden Talos image + CDI CSI storage-layer clone; deletes the `talos-image-cache` workaround	Not merged

#3455 was active in the reference run - cache=unsafe appears three times in the job log and the failure message reads within 18m, the raised value. Its own diff comment describes the motivating case as:

in run 30260770694 a transient drbd.linbit.com/lost-quorum taint delayed the worker DataVolume imports, the worker VMIs were created ~2m into this wait, and the guests then had only ~10m to import Talos, boot, register a kubelet and let cilium turn the nodes Ready. They did not make it: both kubernetes-latest and kubernetes-previous failed here at exactly 12m with zero Nodes registered and the tenant cilium HR still mid-install.

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:

=== (b) in-guest Talos/kubelet capture skipped: no tenant talosconfig on the runner (a/c cover the 2a-vs-2b split) ===

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 Running and 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

Capture the guest side on a failing run: talosctl dmesg and talosctl logs kubelet from a worker that misses the budget. This needs a tenant talosconfig on the runner, which the harness does not currently produce - wiring that into the catch block is the prerequisite, and it is the single highest-value change here.
With that in hand, decide between the two remaining candidates: guest-side slowness that more margin cannot fix (in which case feat(kubernetes): boot tenant worker disks from a shared golden Talos image (CDI clone) #3294's structural change is the answer), versus a genuine stall in Talos bring-up that no timeout will ever absorb.
Do not raise the 18m budget again before (1). The 12m → 18m raise is the datapoint that says widening the window is not converging.

Notes

The reference run belongs to a PR that changes only two workflow YAMLs and a bats test, so it cannot have caused this.
A separate run the same day (30667487982, a PR bumping only indirect Go modules) also failed kubernetes-latest with the same chainsaw assertion ($error == null), but for a different underlying reason - there the nodes joined and the suite failed later on helmreleases/kubernetes-test-latest-version-csi timing out. Worth noting so the generic assertion text is not treated as a single signature.

Fresh evidence from the cozyreport of a recent run (run 30940776005, kubernetes-latest, both host and tenant crust-gather snapshots) 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-signer` sidecar listening
08:35 to 08:36	Workers pull the Talos image from `talos-image-cache` quickly (206/200, no stalls)
08:37:50	Worker VMI `Running` (`...-828wg` on srv1, `...-x7l67` on srv3, spread across nodes)
08:37 to 08:53	Machines `BootstrapReady=True`, `NodeHealthy=False`; no Node ever registers
08:51:56	MHC `nodeStartupTimeout: 10m0s` trips; remediation blocked by `maxUnhealthy: 50%` (total 2, unhealthy 2)
08:53:00	First and only kubelet CSR signed (`...-828wg`); the second worker never requests one

The 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 found errors and the ovn-central backup raft header lines are startup transients confined to a 185ms burst at 06:53:13; the leader kube-ovn-controller then 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.

test(e2e): mirror ghcr.io for tenant worker image pulls

fix(kubernetes): stop registryMirrors comment from breaking the recon…

feat(kubernetes-nodes): add talos.registryMirrors, in parity with the…

test(e2e): harden ghcr-mirror endpoint resolution, drop dead helper

test(e2e): run the ghcr-mirror registry PSS-restricted

fix(e2e): capture ghcr-mirror probe inside if so dash errexit does no…

test(e2e): pin the ghcr-mirror image via mirror.gcr.io and bound its …

docs(kubernetes,kubernetes-nodes): note registryMirrors does not enfo…

fix(e2e): capture Talos logs for tenant worker join failures (#3548)

feat(kubernetes): add talos.registryMirrors for worker image-pull mir…

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-ocpus to mean vCPUs and divide by 2 before the OCI API sees it, but the scale set manifests still pass the old number, so oracle-vm-32cpu-128gb-x86-64 gives 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.0 back 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-cpu each 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/stat reads 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, utime is index 10 of the fields after state, 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: KVM and switch clocksource to kvm-clock, we never set useEmulation so a missing /dev/kvm would 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.

test(e2e): add a container lane for the srv1-srv3 nodes

test(e2e): drop the ghcr.io pull-through mirror

test(e2e): run the merge-gating lanes on Talos containers

feat(kubernetes): boot tenant worker disks from a shared golden Talos…

test(e2e): run the merge-gating lanes on Talos containers (#4020)

closing this as completed by reducing nested virtualization in e2e

feat(kubernetes): boot tenant worker disks from a shared golden Talos…

fix(kubernetes): name TalosConfigTemplate by content hash (#3523)

fix(kubernetes, e2e): unblock autoscaling below min size, size the co…

Navigation Menu

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

Status 2026-08-15

Summary

Fingerprint

Where the time goes

This is not #3229

Prior attempts, and why the newest evidence outlives them

What is blocking a root cause

What would close this

Notes

64 remaining items

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

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

Status 2026-08-15

Summary

Fingerprint

Where the time goes

This is not #3229

Prior attempts, and why the newest evidence outlives them

What is blocking a root cause

What would close this

Notes

Activity

IvanHunters commented on Aug 5, 2026

64 remaining items

lexfrei commented on Aug 18, 2026

lexfrei commented on Aug 20, 2026

lexfrei commented on Aug 20, 2026

myasnikovdaniil commented on Aug 21, 2026

myasnikovdaniil commented on Sep 23, 2026

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions