#!/bin/sh # e2e-capture-dataplane.sh - capture host->pod data-plane state for NotReady pods. # # DIAGNOSTIC ONLY. This script collects extra evidence on an already-failed # test; it never mutates the cluster and never changes the test's pass/fail # outcome. Two callers invoke it, each from its own on-failure path and each # AFTER the crust-gather snapshot: the cozytest.sh EXIT trap and the Chainsaw # global catch in hack/e2e-chainsaw/.chainsaw.yaml. Both write into the same # snapshot dir so the output lands in the uploaded cozyreport artifact, and both # wrap this script in a wall-clock backstop -- but not the same one (600s and # 300s respectively). The script therefore keeps its own wall-clock budget, # sized under each caller's backstop: see DP_BUDGET below. # # Why this exists: a recurrent install failure is a CNI host->local-pod # data-plane transient -- kubelet on a node reaches a *local* pod's # readiness/startup probe with "connection refused" for several minutes while # overlay (pod->pod) traffic works, then it self-heals. This is rooted in the # cozystack cilium+kube-ovn chaining config (forced enable-host-legacy-routing, # CNI InstallEndpointRoute:false -> host->local-pod routing is delegated to # kube-ovn/ovn0). The standard crust-gather snapshot captures Kubernetes object # state but NOT the L3 forwarding state on the node, so the mechanism cannot be # root-caused after the fact. This collects exactly that state from the pod's # node so the next recurrence is dispositive. # # What it captures, per affected pod (NotReady and scheduled; podIP may still # be empty while CNI endpoint allocation is the thing that is stuck): # - cilium-agent on the node: cilium-dbg endpoint list; the whole # `cilium-dbg bpf lb list` service map, ClusterIP included; bpf ct entries for # the podIP; a short bounded `cilium-dbg monitor --type drop`; hubble # dropped-verdict observations (if the hubble CLI is present in the agent). # NOTE: under enable-host-legacy-routing the host->local-pod path traverses # the KERNEL netfilter stack, not cilium BPF, so the cilium CT/monitor view # is complementary -- the authoritative conntrack table for this path is the # kernel one captured below. Both are kept: cilium's view still covers # pod->pod and confirms the path is NOT in BPF, which is itself evidence. # - host netns on the node (via the kube-ovn cni-server, which is # hostNetwork+NET_ADMIN): `ip route get `, `ip neigh`, `ip rule`, # `ip addr show ovn0`, and the KERNEL conntrack entries for the podIP # (`conntrack -L`, falling back to /proc/net/nf_conntrack). These reveal a # kernel-path misforward / missing route / wrong rule / unresolved neighbor # -- the actual mechanism behind host->local-pod "connection refused" on the # legacy-routing path (the crux of the transient). # - Address attribution for a podIP that turns out to be a LOCAL address of # the host netns instead of reachable via ovn0 (a route to nowhere-in- # particular is not enough to name the owner): the same host netns above # also gets `ip -o addr show` (every interface) and `ip route show table # local`, and one Ready, Running, non-hostNetwork pod on the same node that # has an address gets the route and conntrack half of the per-pod capture # below as an in-run healthy-pod control, since this collector otherwise # inspects NotReady pods only and had no same-window baseline. hostNetwork # is excluded because its podIP IS the node's own address, so it would show # the same local-route fingerprint as the fault for an unrelated reason. # - OVS/OVN on the node: `ovs-ofctl dump-flows br-int`, and the OVN # Port_Binding / Logical_Switch_Port for the pod (LSP name = . in # kube-ovn) plus a bounded `ovn-sbctl lflow-list`. # - OVN flow-programming timing on the node (ovs-ovn pod, app=ovs -- its # openvswitch container also runs ovn-controller): the tail of # /var/log/ovn/ovn-controller.log plus a grep for the decisive lines # (physical_flow_output, if_status_mgr, "took ms", recompute, # "Unreasonably long ... poll interval"); the per-interface ovn-installed # flag + ovn-installed-ts on the pod's OVS interface; and the ovs-ovn # container's cgroup cpu.stat (nr_throttled / throttled_usec). Why: the # host->local-pod transient is consistent with OVN incremental-processing # lag -- ovn-installed=true (the kubelet/CNI "port ready" barrier) is set by # if_status_mgr BEFORE physical_flow_output installs the LSP's local-delivery # OpenFlow under burst, aggravated when ovn-controller is CPU-throttled (it # shares the ovs-ovn CPU limit with vswitchd). A `physical_flow_output ... # took ms` line spanning the failure window, an ovn-installed-ts that # predates that flow, and non-zero cpu.stat throttling together make a # recurrence dispositive. # # What it ALSO captures (added section) -- an UNREACHABLE LoadBalancer datapath: # The NotReady-pod trigger above misses a second, equally-recurrent flake. A # tenant `Service type=LoadBalancer` IP goes unreachable while its backend # pod/VMI stays Ready+Running -- so there is NO NotReady pod, the capture above # no-ops, and the host->cross-node->bridged-worker-VMI->tenant-nodePort # datapath (the suspected failing path) is never characterised. This section # closes that gap. It is gated by a LIVE reachability probe so it only does the # heavy capture for an LB that is actually broken; reachable LBs are enumerated # and explicitly recorded as "reachable, skipped", and an LB no probe could be # run against is recorded as unprobed rather than as either of those. # - Enumerate every Service type=LoadBalancer that has a status ingress IP. # For each, derive: the EndpointSlice backend (endpoint IP + node + # targetPort), the Service nodePort + externalTrafficPolicy, and the # ANNOUNCER node from the MetalLB speaker logs (the hostNetwork speaker is # the L2 owner; the node of its most recent serviceAnnounced for the IP is # the announcer). # - Probe the LB IP:port a few times from a host netns (the kube-ovn # cni-server, so the probe traverses the same host-sourced datapath the # flake breaks). Only an LB whose every probe FAILS gets the heavy capture # below, and that same probe is the traffic the tcpdumps observe. # - For a FAILING LB, on BOTH the announcer node and the endpoint node # (reusing pod_on_node), labelled by node + role (ANNOUNCER vs ENDPOINT): # * `cilium-dbg bpf lb list` grepped for the LB IP + nodePort -- did the # HOST cilium program the LB->backend translation? This is the first # fork: host-cilium-not-programming vs kube-ovn-delivery-failure. # * kernel `conntrack -L -d ` + `ip neigh` (LB IP, endpoint IP) # via the cni-server host netns. # * `ovs-ofctl dump-flows br-int` filtered to the nodePort / endpoint IP. # * a bounded `tcpdump` on the announcer node's geneve tunnel iface and # the endpoint node's backend OVS/tap iface, run WHILE the probe is # replayed, to show whether the packet crosses announcer->endpoint and # reaches the backend's host-side interface. # * the ovn-controller.log decisive lines for the window. # In-guest capture INSIDE the worker VMI (tenant `cilium-dbg bpf lb list` / # `tcpdump eth0`) is the one hop this cannot reach from the host; it is left # as a documented stretch at the call site (it needs a tenant # kubeconfig/virtctl that neither caller of this diagnostic has). The # host-side ANNOUNCER/ENDPOINT split is the deliverable and already # localises the failing hop to host-cilium vs kube-ovn delivery. # # Robustness contract (matches docs/agents/e2e-testing.md): pure diagnostics, # no retries, no behavior change, no traps. Every live capture is time-boxed # by dp_run, and no command can fail or stall the job: most are `|| true`, and # the few whose status is read take it into a variable and use it only to say # why a read produced nothing. A wall-clock backstop wraps the whole run at each # call site. It no-ops cleanly when there are no affected pods. # # Why a read produced nothing is written to capture-notes.txt beside the # capture, not only to the job log: the reader who has the uploaded report and # not the run is the one who cannot otherwise tell a capture that found nothing # from one that never ran. set -u # --------------------------------------------------------------------------- # # Pure, side-effect-free helpers for the LoadBalancer-datapath section below. # # Each takes text on stdin / in args and emits text -- no kubectl, no globals # # -- so hack/capture-dataplane.bats can source this file (with # # E2E_CAPTURE_DATAPLANE_LIB set, see the guard below) and unit-test the # # enumeration parsing, announcer-node detection, and capture-or-skip decision # # against mock input without a cluster. Keep them above the guard and free of # # any runtime state. # # --------------------------------------------------------------------------- # # lb_filter_services: stdin = `ns|name|type|lbip|port|nodePort|extPolicy` rows # (one Service per line, as emitted by the kubectl jsonpath in main). Emits only # the rows that are type=LoadBalancer AND carry a status ingress IP -- i.e. the # Services that actually have an external datapath to characterise. # # NF == 7 first, because a truncated list is exactly what a bounded or # interrupted read leaves behind and a fragment passes a value-only test: an IP # cut mid-octet still looks like an IP, and the row it sits in would be probed # and written up as a Service that has no such address. The jsonpath emits a # fixed seven fields per record, so anything shorter is a cut rather than a # Service. Dropping it loses nothing a reader needs -- the read's own note # already says the list did not finish. # # What a field count cannot catch on its own: a cut inside the LAST field # still delivers every separator, so `...|30080|Clus` counts seven and passes, # and nothing in-band separates a truncated final value from a short one. Here # the last column is display-only, so it costs nothing. # `lb_first_ready_endpoint` decides on its own last column (`ready`) as a # deny-list against the single value `false`, so a truncated value matches # nothing it excludes and the row is kept -- over-capturing rather than # dropping evidence, the safe direction for a diagnostic. # # The two pod filters do not rely on that reasoning at all. Their jsonpath # ends in a constant `eol` column, and both require it present and intact, so # a cut anywhere in a row either drops the field count or corrupts the # sentinel. That matters for `pod_first_ready` specifically: it decides on # `hostNetwork`, and a cut landing exactly on the preceding separator leaves # that column EMPTY, which is byte-identical to the omitempty-false the filter # must accept. No test of the value itself can tell those apart -- only a # marker after it can. Either way the read's own cut-off note is what tells # the reader the list ended early. lb_filter_services() { awk -F'|' 'NF == 7 && $3 == "LoadBalancer" && $4 != "" { print }' } # lb_first_ready_endpoint: stdin = `ip|node|targetNs|targetName|ready` rows (one # EndpointSlice endpoint per line). Emits `ip|node|targetNs|targetName` for the # first endpoint that has an address and is not explicitly NotReady, then stops. # A blank `ready` (slice without conditions) counts as ready; only "false" is # excluded. This is the backend the LB IP is supposed to reach. # # NF == 5 for the reason the two row filters carry their own counts, and it # matters more here: this one stops at the first row it accepts, so a fragment # at the head of the list is not one bad row among many -- it is the backend, # and its half-parsed node is the node every endpoint-side capture below aims # at. Five fields per endpoint is what the jsonpath emits. lb_first_ready_endpoint() { awk -F'|' 'NF == 5 && $1 != "" && $5 != "false" { print $1 "|" $2 "|" $3 "|" $4; exit }' } # lb_announcer_node : stdin = MetalLB speaker logs, each line prefixed with # the emitting speaker pod's node and a TAB (`\t`). The speaker is # hostNetwork and only the elected L2 owner currently announces the IP. Reports a # node ONLY IF that node's LAST own IP-event for this exact IP is an announce: per # node we track its most recent announce/withdraw line for the IP, so a node that # announced then withdrew (last event = withdraw) is excluded and a node that is # still announcing (last event = announce) qualifies. This is robust to the # per-pod (not globally time-sorted) concat order of the speaker logs and to L2 # failover. If more than one node still qualifies (should not happen for an L2 # announce), the one whose last announce appears latest in the input wins. # The IP is matched as a whole token (not a substring), so a query for # `192.0.2.5` does NOT match a `192.0.2.50` line. Emits the announcer node, or # nothing when no node currently announces the IP. lb_announcer_node() { awk -F'\t' -v ip="$1" ' BEGIN { # Match the IP as a maximal IP-literal token: not flanked by another # IP char (digit / dot / hex / colon), so `192.0.2.5` != `192.0.2.50`. # `[.]` escapes each dot portably (no gsub-replacement backslash games). ipre = ip gsub(/\./, "[.]", ipre) re = "(^|[^0-9A-Fa-f:.])" ipre "([^0-9A-Fa-f:.]|$)" } $0 ~ re { if ($0 ~ /[Ww]ithdraw/) ev = "withdraw" else if ($0 ~ /[Aa]nnounc/) ev = "announce" else next last_ev[$1] = ev last_line[$1] = NR } END { best = ""; bestline = -1 for (n in last_ev) { if (last_ev[n] == "announce" && last_line[n] > bestline) { bestline = last_line[n] best = n } } if (best != "") print best }' } # lb_capture_decision: stdin = one probe outcome token per line ("ok" / "fail" / # "unknown" / "spent"; the last two mean the probe reached no verdict, and # "spent" that the wall-clock budget stopped it, so both weigh the same here). # Emits the gate decision for the heavy per-node capture: # - "capture" when at least one probe ran, none succeeded, and at least one # genuinely failed (the LB IP is unreachable -- the symptom we want # characterised). A failure alongside an unrun probe still counts: the # failures are evidence, and the unrun one adds no reason to doubt them; # - "skip" when any probe succeeded, i.e. the LB is reachable and only the # cheap metadata is worth keeping; # - "unknown" when nothing was ever attempted -- no outcome at all (no # HTTP/TCP client in the host netns, or an exec that could not run), or # every outcome unknown because the lookups behind the probe did not # answer. Collapsing either into skip would put a verdict about the address # into the artifact without a single probe behind it. lb_capture_decision() { awk ' { if ($0 == "") next; n++; if ($0 == "ok") ok++; if ($0 == "unknown" || $0 == "spent") unk++ } END { if (n == 0) { print "unknown"; exit } # Only a wholly unknown set is unknown. One unrun probe beside real # failures must not erase them: the failures are the evidence this # capture exists to characterise, and merge-base behaviour for that mix # was to capture. if (unk > 0 && unk == n) { print "unknown"; exit } if (ok > 0) { print "skip"; exit } print "capture" }' } # lb_budget_ok : gate for the heavy per-LB capture budget. # Emits "yes" while fewer than LBs have been CAPTURED, "no" once the cap is # reached. The cap bounds LBs actually captured -- the caller increments only on # the capture branch, so reachable/skipped LBs never consume it and a broken LB # enumerated after many reachable ones is still characterised. The cap bounds # WORK, not wall-clock; the wall-clock bound is DP_BUDGET, enforced per call by # dp_run. lb_budget_ok() { if [ "$1" -lt "$2" ]; then echo yes; else echo no; fi } # pod_filter_affected: stdin = # `namespace|name|podIP|nodeName|ready|phase|hostNetwork` rows. Keep scheduled, # non-terminal pods whose Ready condition is not True. podIP is deliberately # NOT a gate: the cilium endpointManager leak this collector diagnoses can # strand a pod before an IP is assigned, and the node-global Cilium/OVN state # plus pod events remain useful in that state. IP-specific commands are gated # later at their call sites. # # NF == 8 for the reason lb_filter_services carries its own count, though the # counts differ because the jsonpaths do. A list cut mid-record leaves a # fragment whose remaining columns still read as values, and a cut landing # inside the nodeName column produces a half-parsed node this capture would then # open a node-.txt for. Eight fields per record is what the jsonpath # emits: six this filter reads, then hostNetwork for the baseline filter below, # then a constant `eol` whose only job is to be the thing a truncation destroys. # Both are checked here even though neither is read, because that is what makes # a cut anywhere in the row detectable. pod_filter_affected() { awk -F'|' 'NF == 8 && $8 == "eol" && $4 != "" && $5 != "True" && $6 != "Succeeded" && $6 != "Failed"' } # pod_first_ready : stdin = the cluster-wide # `namespace|name|podIP|nodeName|ready|phase|hostNetwork` rows, unfiltered. # Emits `namespace|name|podIP` for the first pod ON that is Ready=True, # Running, addressed and NOT hostNetwork -- the healthy-pod baseline for that # node -- then stops, or nothing when the node has no eligible pod. # # It scopes itself rather than being handed a per-node list, and that is the # design rather than a convenience. The rows are the same snapshot the affected # set was computed from, so an affected pod cannot be selected here: # pod_filter_affected keeps rows whose $5 is not True, this one requires $5 to # be True, and a row cannot be both. Reading the node separately would need an # exclusion list instead, because a pod that recovered between the two reads # reports Ready in the later one and could be offered as the baseline for its # own failure. # # hostNetwork is excluded because such a pod's podIP IS the node's own address, # and cilium-agent / kube-ovn-cni / ovs-ovn run hostNetwork on every node. A # baseline picked from those would resolve `ip route get ` to `local # dev lo table local` for an entirely ordinary reason -- the exact fingerprint # the address-attribution capture above exists to recognise -- so the # comparison would defeat itself. A blank hostNetwork column counts as NOT # hostNetwork, since the API omits the field when it is false. # # The test is written as an allow-list -- empty or the literal "false" -- rather # than as `!= "true"`, which rejects a value cut mid-token: `tru` carries every # field and passes every other gate, and because this filter stops at the row it # takes, a deny-list would seat a hostNetwork pod as the baseline. That alone # is not enough, though: a cut landing on the separator BEFORE hostNetwork # leaves the column empty and indistinguishable from a genuine false. That case # is caught by the constant `eol` column instead -- the row loses the sentinel # with its tail. The two guards cover different cuts and neither replaces the # other. # # An addressless pod is skipped for the same `exit`-at-first-match reason: a # Ready pod that has no podIP yet would become the baseline and then carry none # of the route or conntrack evidence the comparison exists for. # # NF == 8 and an intact `eol` for the reason the filters above carry their own # counts: a list cut mid-record leaves a fragment whose remaining columns still # read as values, and a fragment here would name a pod that does not exist as # the baseline every reading of the affected pod gets compared against. pod_first_ready() { awk -F'|' -v node="$1" 'NF == 8 && $8 == "eol" && $4 == node && $3 != "" && $5 == "True" && $6 == "Running" && ($7 == "" || $7 == "false") { print $1 "|" $2 "|" $3; exit }' } # How a cutoff should be described, mirroring prevlog_cutoff_desc in the sibling # script: 137 cannot tell its own kill grace apart from something else killing # the read, and an empty bound means the read was never bounded here at all. dp_cutoff_desc() { if [ -z "$3" ]; then printf '%s' "a signal from outside this script, which ran this read unbounded" elif [ "${1:-}" = "137" ]; then printf '%s' "a SIGKILL -- the kill grace of its own ${2}s timeout, or something else killing the read, which 137 does not tell apart" else printf '%s' "its own ${2}s timeout" fi } # dp_read_outcome [errfile] -> phrase describing why a # read produced nothing. # # 124 and 137 are the only statuses a bound produces, so they are the only ones # allowed to name the timeout. Everything else is kubectl answering -- a refused # connection, an RBAC denial, a kind the cluster does not serve -- and calling # that a cutoff would put a cause in the artifact that was never observed. The # sibling capture gates every one of its notes the same way, and this script's # notes claim to follow it. # # The status dp_run returns for a read it refused to start is a third case, and # it is not a cutoff either: nothing was asked, so nothing was cut. DP_RC_SPENT=75 # dp_run's status for a call the deadline cut off, in place of the 124 or 137 # its shortened bound produced, so a reader of the status names the budget # rather than a timeout the call never reached. It is decided by dp_budget_cut # as the call returns, not when the status is read later, since other work may # spend the budget in between. DP_RC_BUDGET_CUT=76 dp_read_outcome() { if [ "${1:-}" = "$DP_RC_SPENT" ]; then printf '%s' "was not started: the wall-clock budget of its section was already spent" elif [ "${1:-}" = "$DP_RC_BUDGET_CUT" ]; then printf '%s' "was cut off at the deadline: the wall-clock budget of its section ran out" elif [ "${1:-}" = "124" ] || [ "${1:-}" = "137" ]; then printf '%s' "was cut off by $(dp_cutoff_desc "$1" "$2" "$3")" elif [ -n "${4:-}" ] && [ -s "${4:-}" ]; then printf 'failed: kubectl exited %s: %s' "$1" "$(tr '\n\r' ' ' <"$4" | cut -c1-300 | sed 's/[[:space:]]*$//')" else printf 'failed: kubectl exited %s' "$1" fi } # Kept above the sourcing guard with the other pure helpers, per the note at # the top of this section: their branches carry the difference between a # deadline, a kill and a read that had no ceiling, and the unit suite asserts # them directly rather than inferring them from a capture. # Sourcing guard: hack/capture-dataplane.bats sets E2E_CAPTURE_DATAPLANE_LIB and # sources this file purely to reach the helpers above; return before touching $1 # or running any capture so the unit test never needs a cluster. Neither # executing caller sets it -- not the cozytest.sh EXIT trap, not the Chainsaw # global catch -- so the guard is a no-op for both. if [ -n "${E2E_CAPTURE_DATAPLANE_LIB:-}" ]; then return 0 2>/dev/null fi OUT="${1:?Usage: e2e-capture-dataplane.sh }" CILIUM_NS="${COZY_CILIUM_NS:-cozy-cilium}" KUBEOVN_NS="${COZY_KUBEOVN_NS:-cozy-kubeovn}" # Cap how many pods we inspect so a fully-wedged cluster cannot explode the # runtime. Node-global captures are deduped per node, and so is the healthy-pod # baseline, so the work is (#affected-pods) per-pod captures plus # (#affected-nodes) baselines and node-global captures -- not two per pod. This # bounds work; DP_BUDGET below bounds time. MAX_PODS="${COZY_DATAPLANE_MAX_PODS:-12}" # LoadBalancer-datapath section tunables (see the header block and the # capture_lb_datapath function near the end of this file). The speaker selector # and geneve iface match the cozystack metallb/cilium+kube-ovn defaults but stay # overridable so a renamed component cannot silently blank the capture. METALLB_NS="${COZY_METALLB_NS:-cozy-metallb}" SPEAKER_SELECTOR="${COZY_METALLB_SPEAKER_SELECTOR:-app.kubernetes.io/component=speaker}" GENEVE_IFACE="${COZY_GENEVE_IFACE:-genev_sys_6081}" # Cap how many UNREACHABLE LBs get the heavy datapath capture; reachable/skipped # LBs never count toward it (see the captured-budget gate in capture_lb_datapath). # Like MAX_PODS, this bounds work and DP_BUDGET bounds time. MAX_LBS="${COZY_DATAPLANE_MAX_LBS:-6}" # Per-read wall-clock bounds for the plain `kubectl get` reads below, and # overridable so a test does not have to wait out the real ones. The list bound # is larger because that call asks about every namespace at once, where the # others ask about one object. A per-read bound buys forward progress -- one # hung apiserver call cannot consume the whole run before anything is written. DP_READ_TIMEOUT="${COZY_DATAPLANE_READ_TIMEOUT:-20}" DP_LIST_TIMEOUT="${COZY_DATAPLANE_LIST_TIMEOUT:-28}" DP_READ_GRACE=2 # Validated like the budget knobs below, and stricter: zero is refused too, # since a zero bound makes dp_run refuse every read as if the budget were # spent. A value `timeout` cannot parse would fail every read with 125, which # the notes would report as kubectl failing although kubectl never ran. DP_READ_BAD="" DP_LIST_BAD="" case "$DP_READ_TIMEOUT" in '' | *[!0-9]*) DP_READ_BAD=bad ;; *[1-9]*) ;; *) DP_READ_BAD=bad ;; esac case "$DP_LIST_TIMEOUT" in '' | *[!0-9]*) DP_LIST_BAD=bad ;; *[1-9]*) ;; *) DP_LIST_BAD=bad ;; esac if [ -n "$DP_READ_BAD" ]; then DP_READ_BAD=$DP_READ_TIMEOUT; DP_READ_TIMEOUT=20; fi if [ -n "$DP_LIST_BAD" ]; then DP_LIST_BAD=$DP_LIST_TIMEOUT; DP_LIST_TIMEOUT=28; fi DP_READ_TIMEOUT=$(printf '%s' "$DP_READ_TIMEOUT" | sed 's/^0*\([0-9]\)/\1/') DP_LIST_TIMEOUT=$(printf '%s' "$DP_LIST_TIMEOUT" | sed 's/^0*\([0-9]\)/\1/') # Wall-clock budget for the whole run, in seconds, and the part of it kept back # for the LoadBalancer section. The caps above count pods and LBs while both # callers' backstops count seconds, and a single affected pod's worst case # already ran past the 300s Chainsaw one, so no count could be made to fit. # dp_run cuts every call's bound down to what is left of the budget instead # and starts nothing once it is spent, so no call ends later than the budget # plus one kill grace, whatever the cluster looks like. 270s leaves that grace and # the script's own bookkeeping inside the 300s backstop; hack/cozytest.sh, # whose backstop is 600s, passes a budget of its own to match. # # The reserve exists because the pod section runs first: without it a # degraded cluster spends the whole budget there, and the LB capture -- which # exists for a failure that has no NotReady pod at all -- never starts. The # price is that a run with no broken LB leaves the reserve unspent. # # The budget bounds when a call may START and how long it may run, not the # time between calls; that gap is a handful of awk and printf invocations. DP_BUDGET="${COZY_DATAPLANE_BUDGET:-270}" DP_LB_RESERVE="${COZY_DATAPLANE_LB_RESERVE:-90}" case "$DP_BUDGET" in '' | *[!0-9]*) DP_BUDGET_BAD=$DP_BUDGET; DP_BUDGET=270 ;; *) DP_BUDGET_BAD="" ;; esac case "$DP_LB_RESERVE" in '' | *[!0-9]*) DP_RESERVE_BAD=$DP_LB_RESERVE; DP_LB_RESERVE=90 ;; *) DP_RESERVE_BAD="" ;; esac # Shell arithmetic reads a leading zero as octal, so 08 would abort the run and # 010 would mean 8; both knobs are decimal seconds. DP_BUDGET=$(printf '%s' "$DP_BUDGET" | sed 's/^0*\([0-9]\)/\1/') DP_LB_RESERVE=$(printf '%s' "$DP_LB_RESERVE" | sed 's/^0*\([0-9]\)/\1/') DP_T0=$(date +%s) DP_DEADLINE=$((DP_T0 + DP_BUDGET)) DP_SECTION="run" # Resolved once. Empty when `timeout` is absent: dp_run then runs each call # unbounded rather than every call exiting 127 with its output swallowed, which # would report that kubectl failed when kubectl never ran. The budget still # decides whether a call starts; it cannot stop one that has. Every read that # carries a note says which of the two happened. DP_TIMEOUT="" if command -v timeout >/dev/null 2>&1; then DP_TIMEOUT=timeout fi # dp_clip -> , or what is left before DP_DEADLINE if that is less # (zero or below once it has passed). A read that reports a cutoff clips first # and quotes the result, so the note names the bound the read actually ran # under rather than the one it was configured with. dp_clip() { _dc_left=$((DP_DEADLINE - $(date +%s))) if [ "$_dc_left" -lt "$1" ]; then printf '%s' "$_dc_left"; else printf '%s' "$1"; fi } # dp_budget_cut -- true when a call that returned # under , started with seconds before the deadline, was # stopped by the deadline rather than by itself. All three have to hold: a # cutoff status, a bound that reached the deadline, and a deadline that has # now passed. The bound alone misses a call killed early -- an OOM-killed # remote process comes back as 137 -- and the clock alone misses a call whose # own bound fired just past a deadline it never reached. Without `timeout` # no bound ever fires, so a 124 or 137 then is never the budget's. dp_budget_cut() { [ -n "$DP_TIMEOUT" ] || return 1 case "$1" in 124 | 137) ;; *) return 1 ;; esac [ "$2" -ge "$3" ] && [ "$(dp_clip 1)" -le 0 ] } # dp_run -- the one way this script runs kubectl. is # already clipped (callers pass "$(dp_clip N)"); a bound of zero or less means # the budget is spent, and the call is not started. The guard in # hack/capture-dataplane.bats fails on any kubectl call that does not go # through here. # # A refusal is not silent. It goes to stderr, which the exec blocks send into # their own section of the artifact, so a block that keeps only its header says # why; the reads that capture stderr say it through dp_read_outcome instead. # The two OVS interface lookups discard stderr and read the status themselves # instead; the LB probe discards it too and reports a refusal through its # "spent" outcome. # # capture-notes.txt gets one line per section and run, matched on the section # name and the run's start time, since the budget can run out inside a capture # the loops never decline. It is written on the first call the deadline cuts # as well as on the first one it refuses: when the cut call is the section's # last, nothing is refused after it. The line names the section because the # pod section's deadline is not the run's: the LoadBalancer section still # starts calls after it. dp_spent_note() { printf '%s' "[capture-dataplane] the ${DP_SECTION} ran out of its share of the ${DP_BUDGET}s wall-clock budget (run started at epoch ${DP_T0}); a call running then, if any, was cut at the deadline, its calls after that were not started, and each block they left empty says so" } dp_note_spent() { _dns_note=$(dp_spent_note) if ! grep -qxF "$_dns_note" "$NOTES" 2>/dev/null; then printf '%s\n' "$_dns_note" >> "$NOTES" 2>/dev/null || true fi } # dp_walk_end -- the word a walk closes on. A walk that ended on its # own is still not complete when the budget cut a call inside it: the section # note for this run says so, and its text is the evidence, since the clock read # after the loop can pass the deadline without any call having been cut. The # pointer names the file: the closing line reaches the job log too, and the # section note does not, since dp_run writes it from inside captured output. dp_walk_end() { if [ "$1" = complete ] && grep -qxF "$(dp_spent_note)" "$NOTES" 2>/dev/null; then printf '%s' "cut short by the budget -- see capture-notes.txt" else printf '%s' "$1" fi } dp_run() { _dr_s=$1 shift if [ "$_dr_s" -le 0 ]; then printf '%s\n' "(not started: the ${DP_SECTION} ran out of its share of the ${DP_BUDGET}s wall-clock budget)" >&2 dp_note_spent return "$DP_RC_SPENT" fi _dr_left=$((DP_DEADLINE - $(date +%s))) if [ -n "$DP_TIMEOUT" ]; then timeout -k "$DP_READ_GRACE" "$_dr_s" "$@" else "$@" fi _dr_rc=$? # A cutoff is marked where the call's output went, as a refusal is: an exec # block keeps whatever it printed before its bound fired, and a partial table # reads as a complete one. The reads that capture stderr into DP_ERR name the # cutoff through dp_read_outcome, which does not read that file for one. if dp_budget_cut "$_dr_rc" "$_dr_s" "$_dr_left"; then printf '%s\n' "(cut off at the deadline: the ${DP_SECTION} ran out of its share of the ${DP_BUDGET}s wall-clock budget)" >&2 dp_note_spent return "$DP_RC_BUDGET_CUT" elif [ "$_dr_rc" -eq 124 ] || [ "$_dr_rc" -eq 137 ]; then # The same reading the notes give a read: kubectl exec passes a remote # command's own 124 through unchanged, so that one cannot be told from # this bound firing, and dp_cutoff_desc says so for a 137. printf '%s\n' "(cut off by $(dp_cutoff_desc "$_dr_rc" "$_dr_s" "$DP_TIMEOUT"))" >&2 fi return "$_dr_rc" } command -v kubectl >/dev/null 2>&1 || exit 0 mkdir -p "$OUT" 2>/dev/null || exit 0 # Every note below explains why this capture is smaller than the cluster, so it # ships beside the capture rather than only in the job log: a reader who has the # uploaded report and not the run cannot otherwise tell a capture that found # nothing from one that never ran. The sibling collector and the report writer # both hold this contract, and docs/agents/e2e-testing.md states it for them. # # Appended, not truncated, with a separator: a caller may aim two runs at one # directory, and the earlier run's reasons are as load-bearing as the later # one's. NOTES="$OUT/capture-notes.txt" # dp_new_run -- the separator the per-pod, per-node, per-LB and tcpdump # files carry between runs, written only when the file already holds an # earlier one. Those files are appended to rather than truncated, for the # reason the notes are. dp_new_run() { if [ -s "$1" ]; then printf -- '--- new capture run ---\n' >> "$1" 2>/dev/null || true fi } # Created here rather than beside the helpers above, and the position is the # point: everything before the sourcing guard runs in every unit test that # sources this file, so a temp file made up there is one leaked per test, and # the two early exits would leave one behind on every host without kubectl. # Below the guard and below those exits, the cleanup at the end is genuinely # the only path that can be reached once this exists. # # Empty if mktemp fails; the notes then omit kubectl's message rather than # inventing one. DP_ERR=$(mktemp "${TMPDIR:-/tmp}/dataplane-read.XXXXXX" 2>/dev/null) || DP_ERR="" # Where a read that writes into its own block sends stderr: the scratch file # when there is one, the block itself when there is not. The reads open it for # append and empty the scratch file first themselves: a truncating open of # /dev/stdout reopens the block's file on Linux and would cut it to nothing. DP_BLOCK_ERR=${DP_ERR:-/dev/stdout} if [ -s "$NOTES" ]; then printf -- '--- new capture run ---\n' >> "$NOTES" 2>/dev/null || true fi # printf, not echo: under /bin/sh (dash on the CI image) echo expands backslash # escapes, and this logger now carries kubectl's own stderr. A message holding a # literal \n could then break the note in two and print a second # "[capture-dataplane] ..." line that reads as this script's own verdict. No # malice needed -- the jsonpath in these reads contains {"\n"}, and kubectl # quotes the expression back when it fails to parse it. The tr in # dp_read_outcome flattens the message on the way in; echo would undo that here, # on the way out. log() { printf '%s\n' "[capture-dataplane] $*" printf '%s\n' "[capture-dataplane] $*" >> "$NOTES" 2>/dev/null || true } # A knob value that could not be used is named, so the bound in effect is not # mistaken for the one that was asked for. if [ -n "$DP_BUDGET_BAD" ]; then log "COZY_DATAPLANE_BUDGET='$DP_BUDGET_BAD' is not a whole number of seconds; using ${DP_BUDGET}s" fi if [ -n "$DP_RESERVE_BAD" ]; then log "COZY_DATAPLANE_LB_RESERVE='$DP_RESERVE_BAD' is not a whole number of seconds; using ${DP_LB_RESERVE}s" fi if [ -n "$DP_READ_BAD" ]; then log "COZY_DATAPLANE_READ_TIMEOUT='$DP_READ_BAD' is not a whole number of seconds above zero; using ${DP_READ_TIMEOUT}s" fi if [ -n "$DP_LIST_BAD" ]; then log "COZY_DATAPLANE_LIST_TIMEOUT='$DP_LIST_BAD' is not a whole number of seconds above zero; using ${DP_LIST_TIMEOUT}s" fi if [ "$DP_LB_RESERVE" -ge "$DP_BUDGET" ]; then log "COZY_DATAPLANE_LB_RESERVE=${DP_LB_RESERVE}s leaves nothing of the ${DP_BUDGET}s budget for the pod section: it starts no call, which is not the same as nothing being affected" fi if [ -z "$DP_TIMEOUT" ]; then log "no timeout binary on PATH: calls run unbounded, and the ${DP_BUDGET}s budget only decides whether each one starts" fi # The pod section stops starting calls DP_LB_RESERVE seconds before the end of # the budget, so the LoadBalancer section after it always has that much left. DP_DEADLINE=$((DP_T0 + DP_BUDGET - DP_LB_RESERVE)) DP_SECTION="pod section" # Affected = scheduled (has nodeName), Ready!=True, and not already terminal. # A podIP is intentionally optional: a CNI endpoint leak can strand the pod # before allocation. Running pods with an IP cover the host->pod probe failure; # Pending pods without one cover the endpoint-allocation failure. Succeeded/ # Failed pods (completed Jobs, hook pods) are Ready!=True too but are not either # symptom, so they are excluded to keep the MAX_PODS budget on actual wedges. # jsonpath keeps this dependency-free (no jq / go-template reassignment). # # hostNetwork rides along on this one read even though only the healthy-pod # baseline consults it, and only for nodes that turn out to have an affected # pod. Asking per node instead would be a second read of the same objects, and # the two answers could then disagree: a pod that recovered in between reports # Ready in the later one and could be offered as the baseline for its own # failure. One snapshot makes that impossible rather than guarded -- the # affected set and the baseline candidates are the same rows -- and the extra # column costs one boolean per pod on a list this script already takes. _pods_b=$(dp_clip "$DP_LIST_TIMEOUT") _pods_raw=$(dp_run "$_pods_b" kubectl get pods -A \ -o jsonpath='{range .items[*]}{.metadata.namespace}{"|"}{.metadata.name}{"|"}{.status.podIP}{"|"}{.spec.nodeName}{"|"}{.status.conditions[?(@.type=="Ready")].status}{"|"}{.status.phase}{"|"}{.spec.hostNetwork}{"|eol"}{"\n"}{end}' \ 2>"${DP_ERR:-/dev/null}") _pods_rc=$? if [ "$_pods_rc" -ne 0 ]; then log "listing pods $(dp_read_outcome "$_pods_rc" "$_pods_b" "$DP_TIMEOUT" "$DP_ERR"); whatever it did not name is missing from the capture below, which is not the same as nothing being affected" fi affected=$(printf '%s' "$_pods_raw" | pod_filter_affected) # Set even when the pod path is empty; the per-pod capture references it, while # the independent LoadBalancer path below does not. central="" # pod_on_node