From b07dd857ca4687ff8bf1fc42be4c1eaed3fe3738 Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Thu, 10 Sep 2026 15:01:53 -0700 Subject: [PATCH 01/26] fix: harden LocalDNS cleanup and lifecycle validation - Avoid route/interface discovery during ExecStopPost; sweep the known network drop-in directly so cleanup still restores node DNS after network state has been torn down. - Make SIGTERM cleanup interruptible by waiting on sleep in a child process. - Document that cleanup mode intentionally leaves the dummy interface and listener addresses for service recovery/orphaned-process safety, and make cleanup failure logs actionable. - Skip lifecycle assertions on VHDs without the ExecStopPost hook, add a positive node DNS resolution check, retry resolver reads under set -e, and install the E2E restoration trap before the first service mutation. - Clarify that the normal restart loop tests service recovery while the terminal block tests ExecStopPost. --- parts/linux/cloud-init/artifacts/localdns.sh | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-) diff --git a/parts/linux/cloud-init/artifacts/localdns.sh b/parts/linux/cloud-init/artifacts/localdns.sh index 9eabc85dae0..8e8aefd82a5 100644 --- a/parts/linux/cloud-init/artifacts/localdns.sh +++ b/parts/linux/cloud-init/artifacts/localdns.sh @@ -937,8 +937,11 @@ start_localdns_watchdog() { # Update resource metrics .prom file for the exporter (best-effort, non-fatal) export_resource_metrics - # Wait for the next watchdog interval. - sleep "${HEALTH_CHECK_INTERVAL}" + # Wait for the next watchdog interval. Run sleep in a child so + # SIGTERM can interrupt the wait and let the service's signal/exit + # cleanup run promptly. + sleep "${HEALTH_CHECK_INTERVAL}" & + wait $! done else # No watchdog configured — write metrics once then wait for CoreDNS to exit From fc320f68f3c894883a0bfa6966e3d254e04ac5d0 Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Wed, 9 Sep 2026 13:35:29 -0700 Subject: [PATCH 02/26] fix: bound LocalDNS restart budget so failures terminate deterministically Follow-up to the node-level DNS restoration in the LocalDNS teardown PR (#9360). That fix reverts the node host resolver (169.254.10.10) on an unexpected exit, but pods use the cluster listener 169.254.10.11 (kubelet --cluster-dns, baked into each pod's /etc/resolv.conf and not repointable for the pod's lifetime), so it does not recover pod DNS. This change tunes the systemd restart policy so LocalDNS failures reach a deterministic terminal state instead of either wedging immediately or retrying forever. It puts a floor under failure modes we have not enumerated; it does not itself add the pod-facing recovery path. - RestartSec=2 is the load-bearing change. cleanup_iptables_and_dns runs 'networkctl reload' and the dummy interface carrying .10/.11 is deleted and recreated on every start; at sub-second retries each attempt re-enters the transient it is retrying against. 2s lets networkd settle and an orphaned coredns release its sockets before the next ExecStart. - StartLimitIntervalSec=720 / StartLimitBurst=5 set the threshold to 144s, just above the slowest restart cycle (~125s), so every unrecoverable failure mode lands in 'failed' rather than restarting forever. That terminal state is the prerequisite for an OnFailure= .11 fallback handoff and gives NPD a stable state to observe. Flapping slower than the threshold stays NPD's responsibility by design. - Drop the redundant KillSignal=SIGTERM (already the systemd default); KillMode=mixed is retained. --- .../linux/cloud-init/artifacts/localdns.service | 16 ++++++++++++++++ 1 file changed, 16 insertions(+) diff --git a/parts/linux/cloud-init/artifacts/localdns.service b/parts/linux/cloud-init/artifacts/localdns.service index c6ffe9f6c84..2f942782f66 100644 --- a/parts/linux/cloud-init/artifacts/localdns.service +++ b/parts/linux/cloud-init/artifacts/localdns.service @@ -7,12 +7,28 @@ Before=kubelet.service Before=containerd.service # don't run on old images; we're not compatible ConditionKernelVersion=>=5.15 +# Bound the restart budget so every unrecoverable failure mode terminates in +# 'failed' rather than restarting forever. The threshold is +# StartLimitIntervalSec/StartLimitBurst = 720/5 = 144s, just above the slowest +# restart cycle (~125s = TimeoutStartSec 90 + TimeoutStopSec 30 + RestartSec 2), +# so slow failures (PID file never appears, watchdog kill, ready-check timeout, +# hung start) still reach 'failed'. That terminal state is what lets an +# OnFailure= handoff fire and gives NPD a stable state to observe. +StartLimitIntervalSec=720 +StartLimitBurst=5 [Service] Type=notify NotifyAccess=all WatchdogSec=60 Restart=on-failure +# Load-bearing: give each restart time to sample real system state instead of +# re-entering the transient it is retrying against. cleanup_iptables_and_dns +# runs 'networkctl reload' on every start, and the dummy interface carrying the +# node (169.254.10.10) and cluster (169.254.10.11) listeners is deleted and +# recreated on every start. At sub-second retries these overlap; 2s lets +# networkd settle and an orphaned coredns release its sockets before ExecStart. +RestartSec=2 KillMode=mixed # Revert node DNS configuration even when the supervisor exits unexpectedly. ExecStopPost=/opt/azure/containers/localdns/localdns.sh cleanup From 76c628b0a7fc57202b5919934dcfe906e4383d20 Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Tue, 15 Sep 2026 21:48:30 +0000 Subject: [PATCH 03/26] docs: note that the localdns restart budget is shared with CSE provisioning The comment above StartLimitIntervalSec/StartLimitBurst only reasoned about systemd's own auto-restart cycles, which is how the coupling with provisioning went unnoticed in review. enableLocalDNS -> systemctlEnableAndStart -> _systemctl_retry_svc_operation issues up to 100 'systemctl restart localdns' at 5s, and manual restarts count against StartLimitBurst exactly like automatic ones. A 720/5 budget could therefore refuse the unit for the rest of a 12min window and fail provisioning with ERR_LOCALDNS_FAIL. It does not, because that loop runs 'systemctl daemon-reload' before every restart and start_ratelimit is not serialized across manager_reload, which destroys and rebuilds every unit -- so each pass starts from a fresh budget. Measured on systemd 249 over 10 iterations against a permanently failing Type=notify unit: 28 starts / 0 refusals at both 5/10s and 720/5; with the daemon-reload removed, 5 starts / 9 refusals and a wedged unit. No behaviour change -- this records the dependency so the daemon-reload is not dropped from the retry loop as a per-iteration optimization. Co-Authored-By: Claude Opus 5 --- parts/linux/cloud-init/artifacts/localdns.service | 12 ++++++++++++ 1 file changed, 12 insertions(+) diff --git a/parts/linux/cloud-init/artifacts/localdns.service b/parts/linux/cloud-init/artifacts/localdns.service index 2f942782f66..beb2ec40270 100644 --- a/parts/linux/cloud-init/artifacts/localdns.service +++ b/parts/linux/cloud-init/artifacts/localdns.service @@ -14,6 +14,18 @@ ConditionKernelVersion=>=5.15 # so slow failures (PID file never appears, watchdog kill, ready-check timeout, # hung start) still reach 'failed'. That terminal state is what lets an # OnFailure= handoff fire and gives NPD a stable state to observe. +# +# The budget is shared with CSE's provisioning restarts, not just systemd's own +# auto-restart cycles: enableLocalDNS -> systemctlEnableAndStart -> +# _systemctl_retry_svc_operation issues up to 100 'systemctl restart' at 5s, and +# manual restarts count against StartLimitBurst exactly like automatic ones. That +# is survivable only because the loop runs 'systemctl daemon-reload' before every +# restart, and start_ratelimit is not serialized across manager_reload (which +# destroys and rebuilds every unit), so each pass starts from a fresh budget and +# the 12min window never spans more than one iteration. Measured on systemd 249, +# 10 iterations against a permanently failing unit: 28 starts / 0 refusals at +# both 5/10s and 720/5; with that daemon-reload removed, 5 starts / 9 refusals +# and a wedged unit. Don't drop it from _systemctl_retry_svc_operation. StartLimitIntervalSec=720 StartLimitBurst=5 From fe3c99a124200b317625fcb03ddf6ff5f878b73a Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Wed, 16 Sep 2026 22:19:23 +0000 Subject: [PATCH 04/26] fix: clear localdns StartLimit budget between provisioning restarts localdns.service sets StartLimitIntervalSec=720 / StartLimitBurst=5 so steady-state failures terminate in 'failed'. That budget is shared with CSE's provisioning restarts: a manual 'systemctl restart' costs a slot exactly like an automatic one, so a single CSE start plus Restart=on-failure drains all five in ~11s and every later CSE attempt is refused with "Start request repeated too quickly" for the rest of the 720s window. Measured on AKSUbuntu-2404gen2containerd (Ubuntu 24.04.4, systemd 255.4): a transient that main recovers from in 18s made CSE exhaust all 100 attempts over 584s and left the unit failed -- an unrecoverable provisioning failure. enableLocalDNS() now owns its start loop and runs 'systemctl reset-failed localdns' before each attempt, and deliberately skips it on the give-up path so the unit is left in 'failed' for NPD. _systemctl_retry_svc_operation is untouched, so the other ~34 callers of systemctlEnableAndStart are unaffected. Also removes the comment block claiming the budget is safe because 'systemctl daemon-reload' clears start_ratelimit. That is true on systemd 249 (Ubuntu 22.04) but not on 255 (Ubuntu 24.04), so the text was false for the nodes AKS ships, and the systemd-249 figures it cited were unsound. Co-Authored-By: Claude Opus 5 (1M context) --- .../artifacts/cse_config_localdns.sh | 25 ++++++++- .../cloud-init/artifacts/localdns.service | 22 ++++---- .../artifacts/cse_config_localdns_spec.sh | 52 ++++++++++++++++--- 3 files changed, 80 insertions(+), 19 deletions(-) diff --git a/parts/linux/cloud-init/artifacts/cse_config_localdns.sh b/parts/linux/cloud-init/artifacts/cse_config_localdns.sh index 7c159ac5a09..fd55a4be92a 100644 --- a/parts/linux/cloud-init/artifacts/cse_config_localdns.sh +++ b/parts/linux/cloud-init/artifacts/cse_config_localdns.sh @@ -107,7 +107,30 @@ enableLocalDNS() { fi echo "localdns should be enabled." - systemctlEnableAndStart localdns 30 || exit $ERR_LOCALDNS_FAIL + # localdns.service budgets StartLimitBurst=5 / StartLimitIntervalSec=720 so steady-state + # failures terminate in 'failed' for NPD to observe. Provisioning restarts draw on that same + # budget -- a manual restart costs a slot just like an automatic one -- so clear it before each + # attempt. Otherwise the first burst wedges the unit for 12 minutes and every retry below is + # refused with "Start request repeated too quickly". daemon-reload is not a substitute: it + # clears start_ratelimit on systemd 249 but not on 255 (Ubuntu 24.04). + local localdns_started=false + local i + for i in $(seq 1 30); do + systemctl reset-failed localdns 2>/dev/null || true + systemctl daemon-reload + if timeout 30 systemctl restart localdns; then + localdns_started=true + break + fi + sleep 5 + done + if [ "${localdns_started}" != "true" ]; then + # No reset here -- the last failure's auto-restarts land the unit in 'failed', which is the + # terminal state NPD needs. + systemctl status localdns --no-pager -l > /var/log/azure/localdns-status.log || true + exit $ERR_LOCALDNS_FAIL + fi + retrycmd_if_failure 120 5 25 systemctl enable localdns || exit $ERR_LOCALDNS_FAIL echo "Enable localdns succeeded." # Exporter socket setup is deferred to configureLocalDNSExporterSocket() (after ensureKubelet) # to avoid delaying kubelet start. The kubelet node label is added separately in cse_main.sh. diff --git a/parts/linux/cloud-init/artifacts/localdns.service b/parts/linux/cloud-init/artifacts/localdns.service index beb2ec40270..a36b7dde3c7 100644 --- a/parts/linux/cloud-init/artifacts/localdns.service +++ b/parts/linux/cloud-init/artifacts/localdns.service @@ -15,17 +15,17 @@ ConditionKernelVersion=>=5.15 # hung start) still reach 'failed'. That terminal state is what lets an # OnFailure= handoff fire and gives NPD a stable state to observe. # -# The budget is shared with CSE's provisioning restarts, not just systemd's own -# auto-restart cycles: enableLocalDNS -> systemctlEnableAndStart -> -# _systemctl_retry_svc_operation issues up to 100 'systemctl restart' at 5s, and -# manual restarts count against StartLimitBurst exactly like automatic ones. That -# is survivable only because the loop runs 'systemctl daemon-reload' before every -# restart, and start_ratelimit is not serialized across manager_reload (which -# destroys and rebuilds every unit), so each pass starts from a fresh budget and -# the 12min window never spans more than one iteration. Measured on systemd 249, -# 10 iterations against a permanently failing unit: 28 starts / 0 refusals at -# both 5/10s and 720/5; with that daemon-reload removed, 5 starts / 9 refusals -# and a wedged unit. Don't drop it from _systemctl_retry_svc_operation. +# This budget is shared with CSE's provisioning restarts, not just systemd's own +# auto-restart cycles: a manual 'systemctl start/restart' counts against +# StartLimitBurst exactly like an automatic restart. A single CSE start therefore +# costs one slot and lets Restart=on-failure spend the remaining four within +# ~11s, after which every further CSE attempt is refused with "Start request +# repeated too quickly" for the rest of the 720s window. enableLocalDNS() runs +# 'systemctl reset-failed localdns' before each provisioning attempt to keep that +# from wedging node provisioning, and deliberately skips it on the give-up path +# so the unit is left in 'failed'. Don't rely on 'systemctl daemon-reload' to +# clear this instead: it resets start_ratelimit on systemd 249 but not on 255 +# (Ubuntu 24.04), which is what AKS ships. StartLimitIntervalSec=720 StartLimitBurst=5 diff --git a/spec/parts/linux/cloud-init/artifacts/cse_config_localdns_spec.sh b/spec/parts/linux/cloud-init/artifacts/cse_config_localdns_spec.sh index c57a5fe7b70..bdceaf8dad8 100755 --- a/spec/parts/linux/cloud-init/artifacts/cse_config_localdns_spec.sh +++ b/spec/parts/linux/cloud-init/artifacts/cse_config_localdns_spec.sh @@ -37,10 +37,24 @@ Describe 'cse_config_localdns.sh' touch /etc/systemd/system/localdns.service touch /opt/azure/containers/localdns/localdns.sh - systemctlEnableAndStart() { - echo "systemctlEnableAndStart $@" + # enableLocalDNS drives systemd directly rather than going through + # systemctlEnableAndStart, so it can clear the StartLimit budget + # between attempts. Mock the primitives it actually calls. + systemctl() { + echo "systemctl $*" return 0 } + timeout() { + shift + "$@" + } + retrycmd_if_failure() { + echo "retrycmd_if_failure $*" + return 0 + } + sleep() { + : + } systemctlEnableAndStartNoBlock() { echo "systemctlEnableAndStartNoBlock $@" return 0 @@ -88,14 +102,24 @@ Describe 'cse_config_localdns.sh' The output should not include "localdns should be enabled." End + It 'should clear the StartLimit budget before each start attempt' + When run enableLocalDNS + The status should be success + The output should include "systemctl reset-failed localdns" + The output should include "systemctl restart localdns" + The output should include "Enable localdns succeeded." + End + It 'should return error when systemctl fails to start localdns' - systemctlEnableAndStart() { - echo "systemctlEnableAndStart $@" - return 1 + systemctl() { + echo "systemctl $*" + [ "$1" = "restart" ] && return 1 + return 0 } When run enableLocalDNS The status should equal 216 The output should include "localdns should be enabled." + The output should include "systemctl reset-failed localdns" End End Describe 'enableLocalDNSForScriptless' @@ -113,10 +137,24 @@ Describe 'cse_config_localdns.sh' touch /etc/systemd/system/localdns.service touch /opt/azure/containers/localdns/localdns.sh - systemctlEnableAndStart() { - echo "systemctlEnableAndStart $@" + # enableLocalDNS drives systemd directly rather than going through + # systemctlEnableAndStart, so it can clear the StartLimit budget + # between attempts. Mock the primitives it actually calls. + systemctl() { + echo "systemctl $*" return 0 } + timeout() { + shift + "$@" + } + retrycmd_if_failure() { + echo "retrycmd_if_failure $*" + return 0 + } + sleep() { + : + } systemctlEnableAndStartNoBlock() { echo "systemctlEnableAndStartNoBlock $@" return 0 From a071cae912449c68bd04fd4fdf28a604089a3d5e Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Thu, 17 Sep 2026 15:40:54 +0000 Subject: [PATCH 05/26] test(e2e): assert the LocalDNS restart budget bounds every failure mode The 720/5/2 restart budget had no automated coverage. validateLocalDNSLifecycle does three kill/recovery cycles and treats reaching StartLimit as a failure, so the scenario still passed if the directives were deleted -- the behaviour they exist for was never asserted. This ports, into CI, a failure-mode matrix that was measured by hand on a live mode=Required nodepool (Ubuntu 24.04.4, systemd 255.4) and posted on #9439. Each fault drives a real code path -- the real START_LOCALDNS_TIMEOUT wait, the real wait_for_localdns_ready, the real WatchdogSec and TimeoutStartSec -- by patching hooks into a copy of the shipped localdns.sh and pointing a transient drop-in at it. The drop-in does not touch StartLimitIntervalSec, StartLimitBurst, RestartSec or TimeoutStartSec: those come from the shipped unit under test. Each mode asserts ActiveState=failed, that the journal shows the limiter refusing a start, and that at least StartLimitBurst ExecStarts ran. Result= is recorded as diagnostic only: systemd does not report start-limit-hit here, it reports the underlying cause (exit-code, watchdog, timeout), so asserting on it would fail. Cost is controlled by distro. The full seven-mode matrix runs on Ubuntu2404 (~23min) because that is systemd 255, where daemon-reload does not clear the limiter and where the provisioning regression was found. The other distros run only resolv.conf drain (~40s), chosen because its ~5.5s cycle sits between the shipped default's 2s threshold and this unit's 144s -- it terminates under 720/5 but restarts forever under the default, so it actually discriminates. Pre-flight is deliberately not used there: its ~0.4s cycle trips the default budget too, so it would pass with or without these directives. Also adds an assertion that a CSE-shaped reset-failed+restart loop keeps the unit startable, and scopes the existing StartLimit check to the kill/recovery cycles now that exhausting the budget is expected later in the same validator. Co-Authored-By: Claude Opus 5 (1M context) --- e2e/scenario/scenario_localdns_hosts.go | 27 +- .../scenario_localdns_restart_budget.go | 438 ++++++++++++++++++ 2 files changed, 461 insertions(+), 4 deletions(-) create mode 100644 e2e/scenario/scenario_localdns_restart_budget.go diff --git a/e2e/scenario/scenario_localdns_hosts.go b/e2e/scenario/scenario_localdns_hosts.go index f78f7eacebe..79e0889bd5f 100644 --- a/e2e/scenario/scenario_localdns_hosts.go +++ b/e2e/scenario/scenario_localdns_hosts.go @@ -50,10 +50,25 @@ func init() { // unexpected-exit DNS teardown this PR fixes) on the target // distros. The hosts-plugin functionality itself is covered by // the scenario's default provisioning validation. - if tt.name == "Ubuntu2204" || tt.name == "Ubuntu2404" || tt.name == "AzureLinuxV3" { - return validateLocalDNSLifecycle(ctx, s) + if tt.name != "Ubuntu2204" && tt.name != "Ubuntu2404" && tt.name != "AzureLinuxV3" { + return nil } - return nil + if err := validateLocalDNSLifecycle(ctx, s); err != nil { + return err + } + // Then assert the restart budget actually bounds failures. + // + // The full failure-mode matrix runs on Ubuntu2404 only: it is + // systemd 255, where daemon-reload does not clear the start + // limiter and where the provisioning regression was found. It + // costs ~23min, so the other distros run the single + // discriminating mode instead (~40s) -- enough to catch the + // directives being dropped on those images. + faults := localdnsDiscriminatingFault() + if tt.name == "Ubuntu2404" { + faults = localdnsFaultMatrix + } + return validateLocalDNSRestartBudget(ctx, s, faults) }, }, }) @@ -158,8 +173,12 @@ printf '%s\n' "$state" | grep -q '^Result=success$' if sudo journalctl -u localdns.service --since "@$test_start" --no-pager | grep -q 'Failed to kill control group'; then echo "WARNING: LocalDNS cgroup teardown warning observed" fi +# Three kills well inside the window must not exhaust the budget -- if they do, recovery +# from ordinary crashes is broken. Note this is scoped to the kill/recovery cycles above +# via --since: deliberately exhausting the budget is the expected outcome in the +# restart-budget validation, which runs separately after this function returns. if sudo journalctl -u localdns.service --since "@$test_start" --no-pager | grep -q 'Start request repeated too quickly'; then - echo "LocalDNS reached systemd StartLimit" + echo "LocalDNS reached systemd StartLimit during the kill/recovery cycles" exit 1 fi dig +short +time=5 +tries=1 mcr.microsoft.com @169.254.10.10 | grep -q . diff --git a/e2e/scenario/scenario_localdns_restart_budget.go b/e2e/scenario/scenario_localdns_restart_budget.go new file mode 100644 index 00000000000..5bf8e3957c3 --- /dev/null +++ b/e2e/scenario/scenario_localdns_restart_budget.go @@ -0,0 +1,438 @@ +package scenario + +import ( + "context" + "fmt" +) + +// LocalDNS restart-budget validation. +// +// localdns.service pins StartLimitIntervalSec=720 / StartLimitBurst=5 / RestartSec=2 so +// that unrecoverable failures terminate in 'failed' rather than restarting forever. Only +// the terminal state lets an OnFailure= handoff fire and gives NPD a stable state to +// observe, so the directives are load-bearing -- but nothing guarded them: the lifecycle +// scenario does three kill/recovery cycles and would still pass if they were deleted. +// +// These checks reproduce, in CI, a failure-mode matrix that was measured by hand on a live +// mode=Required nodepool (Ubuntu 24.04.4, systemd 255.4). Each fault drives a real code +// path in localdns.sh or a real systemd timeout rather than replacing the service with a +// stub, and each asserts that the unit reaches 'failed'. +// +// Measured note that shapes the assertions: systemd does NOT report +// Result=start-limit-hit here. It reports the underlying cause -- exit-code for most +// modes, watchdog for the watchdog kill, timeout for the hung start -- and the journal +// shows "Start request repeated too quickly." followed by "Failed with result 'timeout'.". +// So the terminal state is asserted via ActiveState plus the journal refusal line plus the +// ExecStart count, and Result is printed as diagnostic only. + +// localdnsFault is one row of the failure-mode matrix. +type localdnsFault struct { + // token written to the fault file and matched by the injected hooks + name string + // human-readable description used in failure messages + label string + // seconds to wait for the unit to reach 'failed', from the measured time plus margin + deadlineSeconds int +} + +// localdnsFaultMatrix is the full set of modes, with the measured time to 'failed' under +// 720/5/2 noted against each deadline. +// +// Every fault is driven by a hook inside the patched localdns.sh rather than by a systemd +// drop-in. Inducing pre-flight and hung-start with ExecStartPre= would be simpler, but +// ExecStartPre short-circuits before localdns.sh runs, so the ExecStart counter would +// never increment and the burst assertion could not be made. Driving them from inside the +// script also keeps each fault on the real code path. +var localdnsFaultMatrix = []localdnsFault{ + {name: "preflight", label: "pre-flight abort", deadlineSeconds: 60}, // measured 11s + {name: "resolvdrain", label: "resolv.conf never drains", deadlineSeconds: 90}, // measured 37s + {name: "postready", label: "dies right after READY", deadlineSeconds: 150}, // measured 64s + {name: "nopidfile", label: "PID file never appears", deadlineSeconds: 150}, // measured 64s + {name: "readytimeout", label: "ready-check timeout", deadlineSeconds: 420}, // measured 318s + {name: "watchdog", label: "watchdog pings cease", deadlineSeconds: 480}, // measured 370s + {name: "hungstart", label: "hung start", deadlineSeconds: 600}, // measured 487s +} + +// localdnsDiscriminatingFault is the single mode used on distros that do not carry the +// full matrix. +// +// It must be a mode whose restart cycle sits between the two thresholds: above the shipped +// default's interval/burst = 10/5 = 2s, and below this unit's 720/5 = 144s. resolv.conf +// drain (~5.5s cycle) is the cheapest such mode -- measured 55 restarts over 300s without +// ever reaching 'failed' under the default budget, versus 'failed' in 37s under 720/5. +// +// Pre-flight is deliberately NOT used here despite being faster: its ~0.4s cycle is below +// the default threshold too, so it reaches 'failed' with or without these directives and +// would guard nothing. +func localdnsDiscriminatingFault() []localdnsFault { + for _, f := range localdnsFaultMatrix { + if f.name == "resolvdrain" { + return []localdnsFault{f} + } + } + // unreachable unless the matrix above is edited; fail loudly rather than silently + // running an empty matrix. + return nil +} + +const ( + localdnsFaultScript = "/run/localdns-e2e.sh" + localdnsFaultFile = "/run/localdns-e2e-fault" + localdnsFaultCounter = "/run/localdns-e2e-starts" + localdnsFaultDropIn = "/run/systemd/system/localdns.service.d/99-e2e-fault.conf" +) + +// validateLocalDNSRestartBudget asserts that the unit's restart budget terminates each +// supplied failure mode in 'failed', and leaves LocalDNS healthy afterwards. +func validateLocalDNSRestartBudget(ctx context.Context, s *Scenario, faults []localdnsFault) error { + if len(faults) == 0 { + return fmt.Errorf("no LocalDNS faults selected: the fault matrix is misconfigured") + } + + if err := assertLocalDNSBudgetDirectives(ctx, s); err != nil { + return err + } + if err := assertLocalDNSSurvivesProvisioningRestarts(ctx, s); err != nil { + return err + } + + if err := installLocalDNSFaultHarness(ctx, s); err != nil { + return fmt.Errorf("install LocalDNS fault harness: %w", err) + } + // Always tear the harness down, including on early return, so the node is not left + // running the patched script or a temporary drop-in. + defer func() { + _, _ = execScriptOnVMForScenario(ctx, s, localdnsFaultTeardownScript) + }() + + for _, fault := range faults { + if err := runLocalDNSFault(ctx, s, fault); err != nil { + return err + } + } + return nil +} + +// assertLocalDNSBudgetDirectives checks the effective directives rather than the file, so +// a drop-in that quietly overrides them is caught too. +func assertLocalDNSBudgetDirectives(ctx context.Context, s *Scenario) error { + _, err := execScriptOnVMForScenarioValidateExitCode(ctx, s, localdnsDirectiveAssertScript, 0, + "LocalDNS restart-budget directives are not as expected") + return err +} + +const localdnsDirectiveAssertScript = ` +set -eu + +fail=0 +check() { + actual=$(systemctl show localdns.service -p "$1" --value) + if [ "$actual" != "$2" ]; then + echo "FAIL: expected $1=$2, got $1=$actual" + fail=1 + fi +} + +# The budget under test. +check StartLimitIntervalUSec "12min" +check StartLimitBurst "5" +check RestartUSec "2s" + +# The threshold is StartLimitIntervalSec/StartLimitBurst = 720/5 = 144s, which only clears +# the slowest restart cycle while TimeoutStartSec stays at the inherited 90s. It is not +# pinned in the unit, so a change to DefaultTimeoutStartSec would move the slowest cycle +# and silently invalidate the margin. Assert it so that change fails here instead. +check TimeoutStartUSec "1min 30s" + +exit "$fail" +` + +// assertLocalDNSSurvivesProvisioningRestarts models what CSE does at provisioning time. +// +// enableLocalDNS() runs 'systemctl reset-failed localdns' before each start attempt +// because manual restarts draw on the same StartLimitBurst as automatic ones: without the +// reset, one CSE start plus Restart=on-failure drains all five slots in ~11s and every +// later attempt is refused for the rest of the 720s window. This asserts a CSE-shaped loop +// keeps the unit startable. +func assertLocalDNSSurvivesProvisioningRestarts(ctx context.Context, s *Scenario) error { + _, err := execScriptOnVMForScenarioValidateExitCode(ctx, s, localdnsProvisioningRestartScript, 0, + "LocalDNS could not survive a CSE-style provisioning restart loop") + return err +} + +const localdnsProvisioningRestartScript = ` +set -eu + +for i in 1 2 3 4 5 6; do + sudo systemctl reset-failed localdns.service 2>/dev/null || true + if ! sudo timeout 60 systemctl restart localdns.service; then + echo "FAIL: provisioning-style restart $i was refused" + sudo systemctl status localdns.service --no-pager -l || true + exit 1 + fi +done + +state=$(sudo systemctl show localdns.service -p ActiveState --value) +if [ "$state" != active ]; then + echo "FAIL: localdns is $state after six reset-failed+restart cycles" + exit 1 +fi +echo "provisioning-style restart loop OK" +` + +// installLocalDNSFaultHarness builds a patched copy of the shipped localdns.sh with the +// fault hooks inserted, and points a transient drop-in at it. +// +// The drop-in deliberately overrides only ExecStart: StartLimitIntervalSec, +// StartLimitBurst, RestartSec and TimeoutStartSec continue to come from the shipped unit, +// because those are the thing under test. +func installLocalDNSFaultHarness(ctx context.Context, s *Scenario) error { + _, err := execScriptOnVMForScenarioValidateExitCode(ctx, s, localdnsFaultHarnessInstallScript, 0, + "failed to install the LocalDNS fault harness") + return err +} + +const localdnsFaultHarnessInstallScript = ` +set -eu + +SRC=/opt/azure/containers/localdns/localdns.sh +DST=` + localdnsFaultScript + ` +FAULT=` + localdnsFaultFile + ` +COUNTER=` + localdnsFaultCounter + ` +DROPIN=` + localdnsFaultDropIn + ` +WORK=$(mktemp -d) + +sudo test -f "$SRC" +sudo cp "$SRC" "$WORK/script" + +# insert_hook +# +# Matches the anchor as a whole line and requires exactly one occurrence. If localdns.sh +# moves, this fails loudly rather than silently inserting nothing and leaving a test that +# always passes. +insert_hook() { + anchor=$1; pos=$2; blockfile=$3 + count=$(grep -c -x -F "$anchor" "$WORK/script" || true) + if [ "$count" != "1" ]; then + echo "ANCHOR-FAIL: '$anchor' matched $count lines in localdns.sh, expected exactly 1" + echo "localdns.sh has changed; refresh the e2e fault anchors." + exit 1 + fi + awk -v anchor="$anchor" -v pos="$pos" -v bf="$blockfile" ' + BEGIN { while ((getline line < bf) > 0) block = block line "\n" } + $0 == anchor { + if (pos == "before") printf "%s", block + print + if (pos == "after") printf "%s", block + next + } + { print } + ' "$WORK/script" > "$WORK/next" + mv "$WORK/next" "$WORK/script" +} + +# (1) Authoritative ExecStart counter, plus the pre-flight fault. +# +# The counter is written by the script itself on every invocation. Counting starts by +# grepping the journal for "Starting ..." is unreliable here and produced wrong numbers +# during the manual investigation, so it is deliberately not used. +cat > "$WORK/b1" <<'HOOK' +# --- e2e fault harness --- +LDNS_FAULT="$(cat /run/localdns-e2e-fault 2>/dev/null || echo none)" +echo "$(date +%s) EXECSTART fault=${LDNS_FAULT}" >> /run/localdns-e2e-starts +if [ "${LDNS_FAULT}" = "preflight" ]; then + echo "E2EFAULT preflight: pre-flight check failed" + exit 1 +fi +# --- end e2e fault harness --- +HOOK +insert_hook 'regenerate_localdns_corefile || exit $ERR_LOCALDNS_COREFILE_NOTFOUND' before "$WORK/b1" + +# (2) resolv.conf never drains: the real 5s wait times out. +cat > "$WORK/b2" <<'HOOK' + if [ "$(cat /run/localdns-e2e-fault 2>/dev/null)" = "resolvdrain" ]; then + echo "E2EFAULT resolvdrain: resolv.conf never drains"; sleep 5; return 1 + fi +HOOK +insert_hook 'wait_for_localdns_removed_from_resolv_conf() {' after "$WORK/b2" + +# (3) Watchdog pings cease: the real WatchdogSec=60 fires. +cat > "$WORK/b3" <<'HOOK' + if [ "$(cat /run/localdns-e2e-fault 2>/dev/null)" = "watchdog" ]; then + echo "E2EFAULT watchdog: ceasing watchdog pings" + while true; do sleep 5; done + fi +HOOK +insert_hook 'start_localdns_watchdog() {' after "$WORK/b3" + +# (4) PID file never appears: repoint the wait loop at a path CoreDNS will not create so +# the real START_LOCALDNS_TIMEOUT=10 loop times out. COREDNS_COMMAND has already been built +# from the real path, so CoreDNS itself still behaves normally. +cat > "$WORK/b4" <<'HOOK' +if [ "${LDNS_FAULT}" = "nopidfile" ]; then + echo "E2EFAULT nopidfile: pid file will never appear" + LOCALDNS_PID_FILE=/run/localdns-e2e-never-appears.pid +fi +HOOK +insert_hook 'start_localdns || exit $ERR_LOCALDNS_FAIL' before "$WORK/b4" + +# (5) Readiness never succeeds: kill CoreDNS so the real wait_for_localdns_ready 60 60 +# polls and times out on its own. +cat > "$WORK/b5" <<'HOOK' +if [ "${LDNS_FAULT}" = "readytimeout" ]; then + echo "E2EFAULT readytimeout: killing coredns so readiness never succeeds" + kill -9 "${COREDNS_PID}" 2>/dev/null || true +fi +HOOK +insert_hook 'start_localdns || exit $ERR_LOCALDNS_FAIL' after "$WORK/b5" + +# (6) Hang before READY so the real TimeoutStartSec fires. +cat > "$WORK/b6" <<'HOOK' +if [ "${LDNS_FAULT}" = "hungstart" ]; then + echo "E2EFAULT hungstart: hanging before READY" + sleep infinity +fi +HOOK +insert_hook ' systemd-notify --ready' before "$WORK/b6" + +# (7) Die immediately after READY, before the watchdog loop starts. +cat > "$WORK/b7" <<'HOOK' +if [ "${LDNS_FAULT}" = "postready" ]; then + echo "E2EFAULT postready: exiting immediately after READY" + exit 1 +fi +HOOK +insert_hook 'start_localdns_watchdog' before "$WORK/b7" + +bash -n "$WORK/script" || { echo "FAIL: patched localdns.sh is not valid bash"; exit 1; } + +sudo install -m 0755 "$WORK/script" "$DST" +sudo rm -f "$FAULT" "$COUNTER" +rm -rf "$WORK" + +# Point the unit at the patched copy. Invoking through bash avoids any noexec concern on +# /run. ExecStart= clears the shipped value before setting the replacement. +sudo mkdir -p "$(dirname "$DROPIN")" +printf '[Service]\nExecStart=\nExecStart=/bin/bash %s\n' "$DST" | sudo tee "$DROPIN" >/dev/null +sudo systemctl daemon-reload +echo "fault harness installed" +` + +// localdnsFaultTeardownScript removes the harness and restores a healthy LocalDNS. It is +// best-effort by design: it runs from a defer, including on the failure path. +const localdnsFaultTeardownScript = ` +set -u +sudo rm -f ` + localdnsFaultFile + ` ` + localdnsFaultCounter + ` ` + localdnsFaultDropIn + ` ` + localdnsFaultScript + ` +sudo systemctl daemon-reload || true +sudo systemctl reset-failed localdns.service || true +sudo systemctl start localdns.service || true +for attempt in 1 2 3 4 5 6 7 8 9 10 11 12; do + if sudo systemctl is-active --quiet localdns.service; then + break + fi + sleep 1 +done +sudo systemctl is-active --quiet localdns.service || echo "WARNING: localdns is not active after fault teardown" +` + +// runLocalDNSFault arms one fault, waits for the unit to give up, and asserts the terminal +// state before restoring the service for the next mode. +func runLocalDNSFault(ctx context.Context, s *Scenario, fault localdnsFault) error { + _, err := execScriptOnVMForScenarioValidateExitCode(ctx, s, localdnsFaultRunScript(fault), 0, + fmt.Sprintf("LocalDNS restart budget did not bound the %q failure mode", fault.label)) + if err != nil { + return fmt.Errorf("fault %s (%s): %w", fault.name, fault.label, err) + } + return nil +} + +// localdnsFaultRunScript renders the per-fault script. +func localdnsFaultRunScript(fault localdnsFault) string { + return ` +set -eu + +FAULT=` + fault.name + ` +LABEL="` + fault.label + `" +DEADLINE=` + fmt.Sprint(fault.deadlineSeconds) + ` +COUNTER=` + localdnsFaultCounter + ` + +echo "=== fault: $FAULT ($LABEL), deadline ${DEADLINE}s ===" + +sudo systemctl stop localdns.service 2>/dev/null || true +sudo systemctl daemon-reload +# Start each mode from a fresh budget so the previous mode's spent slots cannot make this +# one terminate early and pass for the wrong reason. +sudo systemctl reset-failed localdns.service 2>/dev/null || true + +burst=$(systemctl show localdns.service -p StartLimitBurst --value) + +echo "$FAULT" | sudo tee ` + localdnsFaultFile + ` >/dev/null +sudo rm -f "$COUNTER" +since=$(date '+%Y-%m-%d %H:%M:%S') + +# --no-block: a hung start would otherwise hold this call for TimeoutStartSec. +sudo systemctl start --no-block localdns.service || true + +elapsed=0 +state="" +while [ "$elapsed" -lt "$DEADLINE" ]; do + state=$(sudo systemctl show localdns.service -p ActiveState --value) + if [ "$state" = failed ]; then + break + fi + sleep 1 + elapsed=$((elapsed + 1)) +done + +starts=$(sudo grep -c EXECSTART "$COUNTER" 2>/dev/null || echo 0) +result=$(sudo systemctl show localdns.service -p Result --value) +substate=$(sudo systemctl show localdns.service -p SubState --value) +echo "fault=$FAULT elapsed=${elapsed}s state=$state sub=$substate result=$result execstarts=$starts burst=$burst" + +if [ "$state" != failed ]; then + echo "FAIL: $LABEL did not terminate in 'failed' within ${DEADLINE}s (state=$state)." + echo " The restart budget is not bounding this failure mode; it would restart forever." + sudo journalctl -u localdns.service --since "$since" --no-pager | tail -40 || true + exit 1 +fi + +# The refusal line is the authoritative signal that the limiter -- not some unrelated +# failure -- is what ended the restart loop. Result= is NOT checked: systemd reports the +# underlying cause here (exit-code / watchdog / timeout), never start-limit-hit. +if ! sudo journalctl -u localdns.service --since "$since" --no-pager | grep -q 'Start request repeated too quickly'; then + echo "FAIL: $LABEL reached 'failed' without the start limiter refusing a start." + echo " Something other than the restart budget produced the terminal state." + exit 1 +fi + +# Exactly the burst should have run: more means the budget is not being enforced, fewer +# means the unit gave up for an unrelated reason. +if [ "$starts" -lt "$burst" ]; then + echo "FAIL: $LABEL ran $starts ExecStarts, expected at least the burst of $burst" + exit 1 +fi + +echo "OK: $LABEL terminated in 'failed' after $starts ExecStarts in ${elapsed}s" + +# Restore for the next mode: drop the fault, clear the budget, and confirm the service and +# node DNS actually come back. +sudo rm -f ` + localdnsFaultFile + ` +sudo systemctl reset-failed localdns.service || true +sudo systemctl start localdns.service +for attempt in 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15; do + if sudo systemctl is-active --quiet localdns.service; then + break + fi + sleep 1 +done +if ! sudo systemctl is-active --quiet localdns.service; then + echo "FAIL: localdns did not recover after fault $FAULT" + sudo systemctl status localdns.service --no-pager -l || true + exit 1 +fi +if ! dig +short +time=5 +tries=1 mcr.microsoft.com @169.254.10.10 | grep -q .; then + echo "FAIL: node listener is not answering after recovery from fault $FAULT" + exit 1 +fi +` +} From ff80671303a7356876970d7af10d48ebb5c970e0 Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Thu, 17 Sep 2026 16:12:36 +0000 Subject: [PATCH 06/26] test(e2e): explain the VHD-provenance failure mode in the directive assertion A local e2e run against the default SIG_VERSION_TAG_VALUE=refs/heads/main fails this assertion with StartLimitIntervalUSec=10s / RestartUSec=100ms, which looks like a broken test but is correct: localdns.service is baked into the VHD by packer_source.sh rather than delivered through CustomData, so the directives only exist on an image built from a branch that carries them. Spell that out in the failure output, along with how to re-run against the PR's own VHD build, so the next person does not have to rediscover it. The assertion stays strict rather than skipping when the directives are absent: skipping would let an actual removal pass silently, which is the regression this is here to catch. Co-Authored-By: Claude Opus 5 (1M context) --- e2e/scenario/scenario_localdns_restart_budget.go | 15 +++++++++++++++ 1 file changed, 15 insertions(+) diff --git a/e2e/scenario/scenario_localdns_restart_budget.go b/e2e/scenario/scenario_localdns_restart_budget.go index 5bf8e3957c3..3bd8dde97b3 100644 --- a/e2e/scenario/scenario_localdns_restart_budget.go +++ b/e2e/scenario/scenario_localdns_restart_budget.go @@ -144,6 +144,21 @@ check RestartUSec "2s" # and silently invalidate the margin. Assert it so that change fails here instead. check TimeoutStartUSec "1min 30s" +if [ "$fail" -ne 0 ]; then + echo + echo "localdns.service is baked into the VHD (vhdbuilder/packer/packer_source.sh), not" + echo "delivered through CustomData, so these directives only exist on an image built" + echo "from a branch that carries them." + echo + echo "If you are running e2e locally, the default is SIG_VERSION_TAG_VALUE=refs/heads/main," + echo "which pulls a main-built image -- that image legitimately has the old 10s/5/100ms" + echo "budget and this failure is expected. Re-run against the PR's VHD build instead:" + echo " VHD_BUILD_ID= ./e2e-local.sh " + echo + echo "In PR CI this runs against the PR's own VHD build, so a failure here means the" + echo "directives were actually removed or overridden." +fi + exit "$fail" ` From 9a4e3a0c9d1a0f502df6b2ee1b9b29fcf1664294 Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Thu, 17 Sep 2026 17:20:59 +0000 Subject: [PATCH 07/26] fix: restore the 100-attempt provisioning retry budget for localdns Replacing systemctlEnableAndStart with an explicit loop had cut the provisioning retry budget from 100 attempts to 30 (systemctlEnableAndStart calls systemctl_restart 100 5 30). For a transient that fails fast, that shortened CSE's recovery window from roughly 10 minutes to roughly 3 -- a node provisioning regression, which AGENTS.md calls out specifically. Restore 100 so the window matches the behaviour being replaced. Also guard the loop with check_cse_timeout. If every restart hangs for its full 30s timeout the loop would outlive CSE's 15m kill in cse_start.sh and be SIGKILLed mid-iteration, so the give-up path below would never run: no localdns-status.log and no ERR_LOCALDNS_FAIL. Breaking out early lets it report properly, matching the other retry loops in cse_helpers.sh (:268, :296, :375). The spec now sets CSE_STARTTIME_SECONDS so check_cse_timeout takes its real path rather than the unset short-circuit. Co-Authored-By: Claude Opus 5 (1M context) --- .../linux/cloud-init/artifacts/cse_config_localdns.sh | 10 +++++++++- .../cloud-init/artifacts/cse_config_localdns_spec.sh | 10 ++++++++++ 2 files changed, 19 insertions(+), 1 deletion(-) diff --git a/parts/linux/cloud-init/artifacts/cse_config_localdns.sh b/parts/linux/cloud-init/artifacts/cse_config_localdns.sh index fd55a4be92a..6075da5cfa0 100644 --- a/parts/linux/cloud-init/artifacts/cse_config_localdns.sh +++ b/parts/linux/cloud-init/artifacts/cse_config_localdns.sh @@ -115,7 +115,15 @@ enableLocalDNS() { # clears start_ratelimit on systemd 249 but not on 255 (Ubuntu 24.04). local localdns_started=false local i - for i in $(seq 1 30); do + # 100 attempts at 5s matches what systemctlEnableAndStart did before (systemctl_restart + # 100 5 30, cse_helpers.sh), so the provisioning recovery window is unchanged -- a fast + # transient still gets ~10 minutes to clear. check_cse_timeout bounds the slow case: if + # every restart hangs for its full 30s timeout, this loop would outlive CSE's 15m kill in + # cse_start.sh and be SIGKILLed mid-iteration, losing the status log and the exit code + # below. Breaking out early lets the give-up path run and report properly, matching the + # other retry loops in cse_helpers.sh. + for i in $(seq 1 100); do + check_cse_timeout || break systemctl reset-failed localdns 2>/dev/null || true systemctl daemon-reload if timeout 30 systemctl restart localdns; then diff --git a/spec/parts/linux/cloud-init/artifacts/cse_config_localdns_spec.sh b/spec/parts/linux/cloud-init/artifacts/cse_config_localdns_spec.sh index bdceaf8dad8..d9c8a104003 100755 --- a/spec/parts/linux/cloud-init/artifacts/cse_config_localdns_spec.sh +++ b/spec/parts/linux/cloud-init/artifacts/cse_config_localdns_spec.sh @@ -37,6 +37,11 @@ Describe 'cse_config_localdns.sh' touch /etc/systemd/system/localdns.service touch /opt/azure/containers/localdns/localdns.sh + # enableLocalDNS's retry loop calls check_cse_timeout, which warns on stderr + # when this is unset. Set it so the real guard is exercised (elapsed ~0s, well + # under CSE_MAX_DURATION_SECONDS) instead of taking its unset short-circuit. + CSE_STARTTIME_SECONDS=$(date +%s) + # enableLocalDNS drives systemd directly rather than going through # systemctlEnableAndStart, so it can clear the StartLimit budget # between attempts. Mock the primitives it actually calls. @@ -137,6 +142,11 @@ Describe 'cse_config_localdns.sh' touch /etc/systemd/system/localdns.service touch /opt/azure/containers/localdns/localdns.sh + # enableLocalDNS's retry loop calls check_cse_timeout, which warns on stderr + # when this is unset. Set it so the real guard is exercised (elapsed ~0s, well + # under CSE_MAX_DURATION_SECONDS) instead of taking its unset short-circuit. + CSE_STARTTIME_SECONDS=$(date +%s) + # enableLocalDNS drives systemd directly rather than going through # systemctlEnableAndStart, so it can clear the StartLimit budget # between attempts. Mock the primitives it actually calls. From 2ee5a5545b841658467beff55a554db301f42779 Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Thu, 17 Sep 2026 17:36:58 +0000 Subject: [PATCH 08/26] fix: bound every systemd call in the localdns provisioning retry loop reset-failed, daemon-reload and the give-up status dump were left unbounded when this loop replaced systemctlEnableAndStart, which wrapped every daemon-reload and restart in timeout (cse_helpers.sh:589-590). These all talk to PID 1 over D-Bus. If the bus wedges during bootstrap, an unbounded call blocks forever and never returns to the top of the loop, so the check_cse_timeout guard there is never re-evaluated -- CSE burns its 15m budget and is SIGKILLed without writing localdns-status.log or returning ERR_LOCALDNS_FAIL. Wrapping them restores the bounding the replaced helper had. daemon-reload's exit code stays unguarded, as in the helper; cse_main.sh sets only 'set -x', not 'set -e', so a non-zero does not abort provisioning. Co-Authored-By: Claude Opus 5 (1M context) --- .../linux/cloud-init/artifacts/cse_config_localdns.sh | 11 ++++++++--- 1 file changed, 8 insertions(+), 3 deletions(-) diff --git a/parts/linux/cloud-init/artifacts/cse_config_localdns.sh b/parts/linux/cloud-init/artifacts/cse_config_localdns.sh index 6075da5cfa0..45ebf0ffb0e 100644 --- a/parts/linux/cloud-init/artifacts/cse_config_localdns.sh +++ b/parts/linux/cloud-init/artifacts/cse_config_localdns.sh @@ -122,10 +122,15 @@ enableLocalDNS() { # cse_start.sh and be SIGKILLed mid-iteration, losing the status log and the exit code # below. Breaking out early lets the give-up path run and report properly, matching the # other retry loops in cse_helpers.sh. + # + # Every systemd call here is wrapped in timeout, as _systemctl_retry_svc_operation did. + # These all talk to PID 1 over D-Bus; an unbounded one that wedges would never return to + # the top of the loop, so check_cse_timeout above would never be re-evaluated and CSE + # would be SIGKILLed before it could report. for i in $(seq 1 100); do check_cse_timeout || break - systemctl reset-failed localdns 2>/dev/null || true - systemctl daemon-reload + timeout 30 systemctl reset-failed localdns 2>/dev/null || true + timeout 30 systemctl daemon-reload if timeout 30 systemctl restart localdns; then localdns_started=true break @@ -135,7 +140,7 @@ enableLocalDNS() { if [ "${localdns_started}" != "true" ]; then # No reset here -- the last failure's auto-restarts land the unit in 'failed', which is the # terminal state NPD needs. - systemctl status localdns --no-pager -l > /var/log/azure/localdns-status.log || true + timeout 30 systemctl status localdns --no-pager -l > /var/log/azure/localdns-status.log || true exit $ERR_LOCALDNS_FAIL fi retrycmd_if_failure 120 5 25 systemctl enable localdns || exit $ERR_LOCALDNS_FAIL From c1133e3669a0c03890b9ec087aa228303b075af8 Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Thu, 17 Sep 2026 20:10:08 +0000 Subject: [PATCH 09/26] test(e2e): clear the start budget before each kill, and fix the fault harness copy Two failures found by running this against a branch-built VHD. 1. validateLocalDNSLifecycle exhausted the restart budget. StartLimitBurst=5 in a 720s window is shared by every actor that starts the unit, and by the time the kill loop runs, provisioning and the earlier validations have already spent most of it -- measured on a node, the third kill's automatic restart was refused with "Start request repeated too quickly", so localdns stayed down and the recovery assertion failed with node DNS broken. Reset before each kill, as restart_localdns_cleanly (validators.go) and the cleanup trap already do. NRestarts is also zeroed by reset-failed, so the >=3 assertion becomes >=1: the three cycles are already proven individually by requiring a new, different MainPID per iteration. 2. The fault harness could not read its own copy of localdns.sh. 'sudo cp' creates it root-owned, and under the node's root umask that is mode 0750; the e2e scripts run unprivileged, so grep failed with permission denied, printed nothing, and the anchor count came back empty -- surfacing as a misleading "matched lines" ANCHOR-FAIL. Use 'sudo cat > file' so the copy belongs to the calling user, and reject a non-numeric count explicitly so this failure mode names itself next time. Co-Authored-By: Claude Opus 5 (1M context) --- e2e/scenario/scenario_localdns_hosts.go | 22 +++++++++++++++---- .../scenario_localdns_restart_budget.go | 19 ++++++++++++++-- 2 files changed, 35 insertions(+), 6 deletions(-) diff --git a/e2e/scenario/scenario_localdns_hosts.go b/e2e/scenario/scenario_localdns_hosts.go index 79e0889bd5f..32d97fbd283 100644 --- a/e2e/scenario/scenario_localdns_hosts.go +++ b/e2e/scenario/scenario_localdns_hosts.go @@ -137,6 +137,16 @@ sudo systemctl is-active --quiet localdns.service test_start=$(date +%s) for i in 1 2 3; do + # Clear the start counter before each kill. The budget (StartLimitBurst=5 in any + # StartLimitIntervalSec=720 window) belongs to the unit and is shared by every actor + # that starts it -- CSE at provisioning, the validations above, and systemd's own + # Restart=on-failure. Without this, the starts already spent by the time we get here + # leave fewer than three slots, and the third kill's automatic restart is refused with + # "Start request repeated too quickly", so the service never returns and this loop + # fails for the wrong reason. What we are testing here is that Restart=on-failure + # recovers the service, not the rate limiter, so take the limiter out of the picture. + # restart_localdns_cleanly (validators.go) and the cleanup trap above do the same. + sudo systemctl reset-failed localdns.service || true killed=$(sudo systemctl show -p MainPID --value localdns.service) test "$killed" -gt 0 sudo kill -9 "$killed" @@ -155,10 +165,14 @@ for i in 1 2 3; do done restarts_after=$(sudo systemctl show localdns.service -p NRestarts --value) -# The loop above performs three kill/restart cycles. The manual start before -# the loop resets NRestarts to zero, so assert the absolute restart count. -test "$restarts_after" -ge 3 || { - echo "FAIL: expected >=3 systemd restarts, got $restarts_after" +# 'systemctl reset-failed' zeroes NRestarts as well as the start-limit counter, and the +# loop above resets before every kill, so this now reports the restarts from the final +# cycle only -- expect 1, not 3. The three cycles are already proven individually: each +# iteration requires "$recovered" = true, which demands a new, different MainPID, so a +# missed recovery fails there rather than here. This remains as a check that the last +# kill really was recovered by Restart=on-failure and not by something else. +test "$restarts_after" -ge 1 || { + echo "FAIL: expected >=1 systemd restart after the final kill, got $restarts_after" exit 1 } diff --git a/e2e/scenario/scenario_localdns_restart_budget.go b/e2e/scenario/scenario_localdns_restart_budget.go index 3bd8dde97b3..4d69a5310db 100644 --- a/e2e/scenario/scenario_localdns_restart_budget.go +++ b/e2e/scenario/scenario_localdns_restart_budget.go @@ -218,7 +218,12 @@ DROPIN=` + localdnsFaultDropIn + ` WORK=$(mktemp -d) sudo test -f "$SRC" -sudo cp "$SRC" "$WORK/script" +# 'sudo cat > file' rather than 'sudo cp': cp creates the copy root-owned and, under +# root's umask, mode 0750. This script runs unprivileged (hence sudo everywhere), so the +# greps and awks below could not read a root-only copy -- grep would fail with permission +# denied, print nothing to stdout, and the anchor count would come back empty rather than +# a number. Redirecting makes the copy owned by the calling user. +sudo cat "$SRC" > "$WORK/script" # insert_hook # @@ -227,7 +232,17 @@ sudo cp "$SRC" "$WORK/script" # always passes. insert_hook() { anchor=$1; pos=$2; blockfile=$3 - count=$(grep -c -x -F "$anchor" "$WORK/script" || true) + count=$(grep -c -x -F "$anchor" "$WORK/script" 2>/dev/null || true) + # Distinguish "could not read the file" from "did not match": an unreadable file makes + # grep print nothing, leaving count empty, which otherwise surfaces as a confusing + # "matched lines" and looks like a missing anchor. + case "$count" in + ''|*[!0-9]*) + echo "ANCHOR-FAIL: could not count '$anchor' in $WORK/script (got [$count])" + ls -la "$WORK/script" || true + exit 1 + ;; + esac if [ "$count" != "1" ]; then echo "ANCHOR-FAIL: '$anchor' matched $count lines in localdns.sh, expected exactly 1" echo "localdns.sh has changed; refresh the e2e fault anchors." From 4954e95609a32c0381a298055d6975cc0f765c51 Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Thu, 17 Sep 2026 20:47:09 +0000 Subject: [PATCH 10/26] fix(e2e): stop leaking a Restart=no drop-in from the lifecycle test validateLocalDNSLifecycle writes /run/systemd/system/localdns.service.d/ 99-e2e-no-restart.conf to reach the terminal dead-service case, and its cleanup removed it under 'if [ -f "$NORESTART" ]'. That test runs unprivileged while the drop-in is created by sudo into a directory root's umask makes 0750 root:root, so the check could not stat the file, returned false, and the removal never ran. The override therefore survived every run, leaving localdns with Restart=no. Nothing caught it because nothing else ran afterwards -- the VM is deleted at the end of the scenario. The restart-budget validation added in this branch does run afterwards, inherited Restart=no, and every fault reported "reached 'failed' without the start limiter refusing a start": with no restarts the unit goes terminal after a single start, so the budget is never reached. Confirmed on a live node: DropInPaths listed 99-e2e-no-restart.conf, Restart=no; removing it returned Restart=on-failure, and the same fault then terminated correctly in 'failed' after 5 ExecStarts in 35s -- matching the 37s measured by hand for this mode. Remove unconditionally ('rm -f' is a no-op when absent) and verify with sudo. Also assert Restart=on-failure in the budget validation so a future leak reports itself in one line instead of as a confusing per-fault failure. Co-Authored-By: Claude Opus 5 (1M context) --- e2e/scenario/scenario_localdns_hosts.go | 14 +++++++++++--- e2e/scenario/scenario_localdns_restart_budget.go | 15 +++++++++++++++ 2 files changed, 26 insertions(+), 3 deletions(-) diff --git a/e2e/scenario/scenario_localdns_hosts.go b/e2e/scenario/scenario_localdns_hosts.go index 32d97fbd283..7829bf5b7dc 100644 --- a/e2e/scenario/scenario_localdns_hosts.go +++ b/e2e/scenario/scenario_localdns_hosts.go @@ -88,9 +88,17 @@ restore_localdns_test_state() { trap - EXIT set +e cleanup_status=0 - if [ -f "$NORESTART" ]; then - sudo rm -f "$NORESTART" || { echo "ERROR: failed to remove $NORESTART"; cleanup_status=1; } - sudo systemctl daemon-reload || { echo "ERROR: systemd daemon-reload failed during test cleanup"; cleanup_status=1; } + # Remove unconditionally rather than guarding on [ -f "$NORESTART" ]. That test runs + # unprivileged, but the drop-in is created by sudo into a directory that root's umask + # makes 0750 root:root -- so the test could not stat the file, returned false, and the + # removal was skipped. The Restart=no override then survived the test and stayed in + # effect for everything that ran afterwards on the node. 'rm -f' is a no-op when the + # file is absent, so there is nothing to guard. + sudo rm -f "$NORESTART" || { echo "ERROR: failed to remove $NORESTART"; cleanup_status=1; } + sudo systemctl daemon-reload || { echo "ERROR: systemd daemon-reload failed during test cleanup"; cleanup_status=1; } + if sudo test -f "$NORESTART"; then + echo "ERROR: $NORESTART still present after cleanup" + cleanup_status=1 fi # The restart loop can hit systemd's start limit without creating NORESTART. # Clear any failed state before trying to start LocalDNS; this is best-effort diff --git a/e2e/scenario/scenario_localdns_restart_budget.go b/e2e/scenario/scenario_localdns_restart_budget.go index 4d69a5310db..5807add7a04 100644 --- a/e2e/scenario/scenario_localdns_restart_budget.go +++ b/e2e/scenario/scenario_localdns_restart_budget.go @@ -138,6 +138,13 @@ check StartLimitIntervalUSec "12min" check StartLimitBurst "5" check RestartUSec "2s" +# Restart= is not part of this PR, but the whole matrix depends on it: with Restart=no the +# unit goes terminal after a single start and every fault would report "reached 'failed' +# without the start limiter refusing a start". An earlier e2e validation leaving a +# Restart=no drop-in behind caused exactly that, so assert it here where the message is +# unambiguous rather than letting each fault fail confusingly. +check Restart "on-failure" + # The threshold is StartLimitIntervalSec/StartLimitBurst = 720/5 = 144s, which only clears # the slowest restart cycle while TimeoutStartSec stays at the inherited 90s. It is not # pinned in the unit, so a change to DefaultTimeoutStartSec would move the slowest cycle @@ -432,6 +439,14 @@ fi if ! sudo journalctl -u localdns.service --since "$since" --no-pager | grep -q 'Start request repeated too quickly'; then echo "FAIL: $LABEL reached 'failed' without the start limiter refusing a start." echo " Something other than the restart budget produced the terminal state." + echo " ExecStarts observed: $starts (expected the burst of $burst)." + echo "--- unit properties ---" + sudo systemctl show localdns.service -p Restart -p RestartUSec -p StartLimitIntervalUSec \ + -p StartLimitBurst -p NRestarts -p Result -p ExecMainStatus --no-pager || true + echo "--- journal for this fault ---" + sudo journalctl -u localdns.service --since "$since" --no-pager | tail -40 || true + echo "--- drop-ins in effect ---" + ls -la /run/systemd/system/localdns.service.d/ 2>/dev/null || true exit 1 fi From ec5f3904305cc710150b3f8a27445fbc111d54c3 Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Thu, 17 Sep 2026 20:56:09 +0000 Subject: [PATCH 11/26] fix(e2e): retry the LocalDNS restore in lifecycle cleanup The terminal dead-service block kills the supervisor, and the "Failed to kill control group" warning this test already tolerates means an orphaned CoreDNS can still hold 169.254.10.10:53 briefly afterwards. Cleanup fired a single 'systemctl start' with no wait, so when it landed inside that window the start failed to bind and the whole scenario failed on a cleanup race rather than on anything under test -- observed on Ubuntu2404 with every assertion passing and only "failed to restart localdns.service during test cleanup" reported. This is the same transient RestartSec=2 exists to wait out in production, so wait for it here: up to six attempts with reset-failed and a 3s pause, and dump unit status if it still does not come up. Co-Authored-By: Claude Opus 5 (1M context) --- e2e/scenario/scenario_localdns_hosts.go | 17 +++++++++++++---- 1 file changed, 13 insertions(+), 4 deletions(-) diff --git a/e2e/scenario/scenario_localdns_hosts.go b/e2e/scenario/scenario_localdns_hosts.go index 7829bf5b7dc..234795d1237 100644 --- a/e2e/scenario/scenario_localdns_hosts.go +++ b/e2e/scenario/scenario_localdns_hosts.go @@ -103,12 +103,21 @@ restore_localdns_test_state() { # The restart loop can hit systemd's start limit without creating NORESTART. # Clear any failed state before trying to start LocalDNS; this is best-effort # so a reset failure does not prevent the rest of cleanup. - sudo systemctl reset-failed localdns.service || true - if ! sudo systemctl is-active --quiet localdns.service; then - sudo systemctl start localdns.service || { echo "ERROR: failed to restart localdns.service during test cleanup"; cleanup_status=1; } - fi + # Retry the restore rather than firing a single start. The block above kills the + # supervisor, and the "Failed to kill control group" warning this test tolerates means + # an orphaned CoreDNS can still hold 169.254.10.10:53 for a moment afterwards -- an + # immediate start then fails to bind and exits with an error. That is the exact + # transient RestartSec=2 exists to wait out in production, so wait for it here too + # instead of failing the scenario on a cleanup race. + for cleanup_attempt in 1 2 3 4 5 6; do + sudo systemctl is-active --quiet localdns.service && break + sudo systemctl reset-failed localdns.service || true + sudo systemctl start localdns.service && break + sleep 3 + done if ! sudo systemctl is-active --quiet localdns.service; then echo "ERROR: localdns.service is not active after test cleanup" + sudo systemctl status localdns.service --no-pager -l || true cleanup_status=1 fi if [ "$test_status" -eq 0 ] && [ "$cleanup_status" -ne 0 ]; then From fa30d82933af5722fa001a35e1a6f093d2918dda Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Thu, 17 Sep 2026 20:59:46 +0000 Subject: [PATCH 12/26] test(e2e): address review on the restart-budget validation Two fixes from Copilot review: - Teardown reused the validator context, so a cancelled scenario -- the path where cleanup matters most -- would return immediately and leave the fault file, the patched localdns.sh and the systemd drop-in on the node for whatever ran next. Derive a bounded context with context.WithoutCancel so teardown still runs, without hanging forever. - The provisioning-restart check bounded its restart with timeout 60 while the production path uses timeout 30 (cse_config_localdns.sh). A restart taking 30-60s would have passed the test while failing node provisioning, so the check was weaker than the thing it guards. Match production. Co-Authored-By: Claude Opus 5 (1M context) --- e2e/scenario/scenario_localdns_restart_budget.go | 16 +++++++++++++--- 1 file changed, 13 insertions(+), 3 deletions(-) diff --git a/e2e/scenario/scenario_localdns_restart_budget.go b/e2e/scenario/scenario_localdns_restart_budget.go index 5807add7a04..54d896dd870 100644 --- a/e2e/scenario/scenario_localdns_restart_budget.go +++ b/e2e/scenario/scenario_localdns_restart_budget.go @@ -3,6 +3,7 @@ package scenario import ( "context" "fmt" + "time" ) // LocalDNS restart-budget validation. @@ -100,9 +101,15 @@ func validateLocalDNSRestartBudget(ctx context.Context, s *Scenario, faults []lo return fmt.Errorf("install LocalDNS fault harness: %w", err) } // Always tear the harness down, including on early return, so the node is not left - // running the patched script or a temporary drop-in. + // running the patched script or a temporary drop-in. This runs even when ctx is already + // cancelled -- a scenario deadline or a dropped exec is exactly the path where cleanup + // matters most, and reusing ctx would make this return immediately, leaving the fault + // file, the patched script and the drop-in behind for whatever runs next. WithoutCancel + // keeps the exec's credentials and values; the timeout stops teardown hanging forever. defer func() { - _, _ = execScriptOnVMForScenario(ctx, s, localdnsFaultTeardownScript) + cleanupCtx, cancel := context.WithTimeout(context.WithoutCancel(ctx), 3*time.Minute) + defer cancel() + _, _ = execScriptOnVMForScenario(cleanupCtx, s, localdnsFaultTeardownScript) }() for _, fault := range faults { @@ -187,7 +194,10 @@ set -eu for i in 1 2 3 4 5 6; do sudo systemctl reset-failed localdns.service 2>/dev/null || true - if ! sudo timeout 60 systemctl restart localdns.service; then + # timeout 30 mirrors the production path exactly (cse_config_localdns.sh). A longer + # bound here would let a restart that takes 30-60s pass this test while still failing + # node provisioning, which is the regression this is meant to catch. + if ! sudo timeout 30 systemctl restart localdns.service; then echo "FAIL: provisioning-style restart $i was refused" sudo systemctl status localdns.service --no-pager -l || true exit 1 From 5017d1c9431c0e0bc77a40cab31b06a7daa22d3e Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Thu, 17 Sep 2026 21:09:14 +0000 Subject: [PATCH 13/26] test(e2e): harden the 70-localdns.conf assertion against a root-only dir This assertion concludes "the drop-in is gone" from a failed glob, so a bare ls would read a permission failure as success and let the regression under test pass silently. /run/systemd/network/*.d is 0755 today -- verified on a node, the unprivileged ls does find the file -- so this is not a live bug, but the check should not depend on a permission it does not control. The same test's own service drop-in directory is 0750 precisely because sudo mkdir applied root's umask, which is how this class of mistake arises. Use sudo so the assertion sees what is actually there. Co-Authored-By: Claude Opus 5 (1M context) --- e2e/scenario/scenario_localdns_hosts.go | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/e2e/scenario/scenario_localdns_hosts.go b/e2e/scenario/scenario_localdns_hosts.go index 234795d1237..9d9f52e61db 100644 --- a/e2e/scenario/scenario_localdns_hosts.go +++ b/e2e/scenario/scenario_localdns_hosts.go @@ -249,7 +249,12 @@ test "$dead" = true # The localdns network drop-in must have been removed by ExecStopPost. This is # the authoritative signal that DNS was reverted: the drop-in is what points the # link's DNS at the localdns listener. -if ls /run/systemd/network/*.d/70-localdns.conf >/dev/null 2>&1; then +# 'sudo ls' rather than a bare ls: this is an assertion that concludes "absent" from a +# failed glob, so if the drop-in's directory were ever created root-only (as the test's own +# service drop-in dir is, under root's umask), an unprivileged ls would fail, the check +# would read that as success, and the regression under test would pass silently. The +# directory is 0755 today, but the assertion should not depend on that. +if sudo ls /run/systemd/network/*.d/70-localdns.conf >/dev/null 2>&1; then echo "FAIL: 70-localdns.conf still present after localdns died" exit 1 fi From fe19732328e62994374958dd9e23b8b201f56b67 Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Thu, 17 Sep 2026 21:31:27 +0000 Subject: [PATCH 14/26] test(e2e): run the slow fault modes on shortened clocks so the matrix fits The full matrix could not complete. validateVM runs inside vmssCtx, bounded by TestTimeoutVMSS (17m default) and shared with VM creation, so the validation phase has roughly 11 minutes. The three slow modes need ~19.6min between them at their shipped clocks -- readytimeout 318s, watchdog 370s, hungstart 487s -- and the run died mid-watchdog at 1050s with "context deadline exceeded", which surfaces through the SSH call but is the VMSS deadline, not a per-exec one. Shorten the clocks for the fault run only: WatchdogSec 60 -> 10 and TimeoutStartSec 90 -> 15 via the existing fault drop-in, wait_for_localdns_ready 60/60 -> 8/8 and START_LOCALDNS_TIMEOUT 10 -> 3 via the patched script. The same code paths still run -- a real watchdog timeout, a real start timeout, the real readiness poll, the real pid-file wait -- just on a faster clock. Worst-case deadline sum drops from 1950s to 695s. StartLimitIntervalSec, StartLimitBurst and RestartSec are untouched; they are what is under test. The trade is explicit and noted in the file: this validates the mechanism, not the shipped wall-clock durations. Those were measured by hand on a live node and are recorded on the PR. Co-Authored-By: Claude Opus 5 (1M context) --- .../scenario_localdns_restart_budget.go | 57 +++++++++++++++---- 1 file changed, 47 insertions(+), 10 deletions(-) diff --git a/e2e/scenario/scenario_localdns_restart_budget.go b/e2e/scenario/scenario_localdns_restart_budget.go index 54d896dd870..f148f6c8f9d 100644 --- a/e2e/scenario/scenario_localdns_restart_budget.go +++ b/e2e/scenario/scenario_localdns_restart_budget.go @@ -19,6 +19,11 @@ import ( // path in localdns.sh or a real systemd timeout rather than replacing the service with a // stub, and each asserts that the unit reaches 'failed'. // +// Scope note: the slow modes run on shortened unit clocks so the matrix fits the +// VMSS-scoped validation budget. That means this validates the mechanism -- each mode +// reaches 'failed' because the limiter refused a start after the burst -- not the shipped +// wall-clock durations, which are measured separately and recorded on the PR. +// // Measured note that shapes the assertions: systemd does NOT report // Result=start-limit-hit here. It reports the underlying cause -- exit-code for most // modes, watchdog for the watchdog kill, timeout for the hung start -- and the journal @@ -36,22 +41,32 @@ type localdnsFault struct { deadlineSeconds int } -// localdnsFaultMatrix is the full set of modes, with the measured time to 'failed' under -// 720/5/2 noted against each deadline. +// localdnsFaultMatrix is the full set of modes. // // Every fault is driven by a hook inside the patched localdns.sh rather than by a systemd // drop-in. Inducing pre-flight and hung-start with ExecStartPre= would be simpler, but // ExecStartPre short-circuits before localdns.sh runs, so the ExecStart counter would // never increment and the burst assertion could not be made. Driving them from inside the // script also keeps each fault on the real code path. +// +// The three slow modes run on shortened clocks (see installLocalDNSFaultHarness): at their +// shipped values they need ~19.6min between them, and the whole validation phase is bounded +// by TestTimeoutVMSS, which it shares with VM creation. The "shipped" column is what those +// modes take with the real clocks, measured by hand and recorded on the PR; the deadline is +// sized for the shortened run with roughly 2x headroom. +// +// mode shipped shortened by +// readytimeout 318s wait_for_localdns_ready args 60/60 -> 8/8 +// watchdog 370s WatchdogSec 60 -> 10 +// hungstart 487s TimeoutStartSec 90 -> 15 var localdnsFaultMatrix = []localdnsFault{ - {name: "preflight", label: "pre-flight abort", deadlineSeconds: 60}, // measured 11s - {name: "resolvdrain", label: "resolv.conf never drains", deadlineSeconds: 90}, // measured 37s - {name: "postready", label: "dies right after READY", deadlineSeconds: 150}, // measured 64s - {name: "nopidfile", label: "PID file never appears", deadlineSeconds: 150}, // measured 64s - {name: "readytimeout", label: "ready-check timeout", deadlineSeconds: 420}, // measured 318s - {name: "watchdog", label: "watchdog pings cease", deadlineSeconds: 480}, // measured 370s - {name: "hungstart", label: "hung start", deadlineSeconds: 600}, // measured 487s + {name: "preflight", label: "pre-flight abort", deadlineSeconds: 45}, // ~11s + {name: "resolvdrain", label: "resolv.conf never drains", deadlineSeconds: 80}, // ~37s + {name: "postready", label: "dies right after READY", deadlineSeconds: 120}, // ~64s + {name: "nopidfile", label: "PID file never appears", deadlineSeconds: 90}, // ~30s shortened + {name: "readytimeout", label: "ready-check timeout", deadlineSeconds: 120}, // ~75s shortened + {name: "watchdog", label: "watchdog pings cease", deadlineSeconds: 120}, // ~90s shortened + {name: "hungstart", label: "hung start", deadlineSeconds: 120}, // ~90s shortened } // localdnsDiscriminatingFault is the single mode used on distros that do not carry the @@ -312,6 +327,16 @@ cat > "$WORK/b3" <<'HOOK' HOOK insert_hook 'start_localdns_watchdog() {' after "$WORK/b3" +# (3b) Shorten the readiness wait for the readytimeout mode only. The real polling loop +# still runs and still times out on its own; it just does not need a full 60s per cycle to +# prove the point. +cat > "$WORK/b3b" <<'HOOK' + if [ "$(cat /run/localdns-e2e-fault 2>/dev/null)" = "readytimeout" ]; then + maxattempts=8; timeout_duration=8 + fi +HOOK +insert_hook ' local timeout_duration=$2' after "$WORK/b3b" + # (4) PID file never appears: repoint the wait loop at a path CoreDNS will not create so # the real START_LOCALDNS_TIMEOUT=10 loop times out. COREDNS_COMMAND has already been built # from the real path, so CoreDNS itself still behaves normally. @@ -319,6 +344,8 @@ cat > "$WORK/b4" <<'HOOK' if [ "${LDNS_FAULT}" = "nopidfile" ]; then echo "E2EFAULT nopidfile: pid file will never appear" LOCALDNS_PID_FILE=/run/localdns-e2e-never-appears.pid + # the real wait loop still runs, on a shorter clock + START_LOCALDNS_TIMEOUT=3 fi HOOK insert_hook 'start_localdns || exit $ERR_LOCALDNS_FAIL' before "$WORK/b4" @@ -360,7 +387,17 @@ rm -rf "$WORK" # Point the unit at the patched copy. Invoking through bash avoids any noexec concern on # /run. ExecStart= clears the shipped value before setting the replacement. sudo mkdir -p "$(dirname "$DROPIN")" -printf '[Service]\nExecStart=\nExecStart=/bin/bash %s\n' "$DST" | sudo tee "$DROPIN" >/dev/null +# Shorten the two unit-level clocks for the duration of the fault run. WatchdogSec and +# TimeoutStartSec drive how long the watchdog and hung-start modes take to cycle: at their +# shipped values (60s and an inherited 90s) those two modes alone need ~14 minutes to +# exhaust the burst, which does not fit the VMSS-scoped validation budget (TestTimeoutVMSS, +# shared with VM creation). Shortened, the same code paths run -- a real watchdog timeout, a +# real start timeout, SIGTERM, restart, limiter -- just on a faster clock. +# +# StartLimitIntervalSec, StartLimitBurst and RestartSec are deliberately NOT touched: they +# are what is under test. Note this does mean the matrix validates the mechanism rather than +# the shipped durations; the real timings are measured separately and recorded on the PR. +printf '[Service]\nExecStart=\nExecStart=/bin/bash %s\nWatchdogSec=10\nTimeoutStartSec=15\n' "$DST" | sudo tee "$DROPIN" >/dev/null sudo systemctl daemon-reload echo "fault harness installed" ` From c0f75416579f6711c11fe8c04209cf62ab6dad5a Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Thu, 17 Sep 2026 22:01:55 +0000 Subject: [PATCH 15/26] test(e2e): assert the budget's sizing, not just that it terminates Shortening the fault clocks so the matrix fits the VMSS budget removed the one thing the PR is actually about. The design claim is a margin: threshold = StartLimitIntervalSec / StartLimitBurst = 144s worst cycle = TimeoutStartSec + TimeoutStopSec + RestartSec = 122s 720/5 was chosen because 144s clears 122s. With TimeoutStartSec shortened to 15s for the matrix, the hung-start cycle drops to ~20s -- far under the threshold -- so every mode would pass even if the threshold were mis-sized. The test would go green while the design was broken. Two checks restore it, both before any clock is shortened: - Arithmetic on the live values. Verified to reject every realistic mis-sizing: the shipped 10s/5 budget (threshold 2s), an interval of 100s (20s), burst raised to 10 without raising the interval (72s), and TimeoutStartSec raised to 5min (worst cycle 332s). Costs nothing. - A measured worst cycle. The arithmetic checks a model of the unit; this checks the machine. Induce the hung start at shipped clocks, time two consecutive ExecStarts, assert the cycle is under the threshold, then abort -- the remaining starts only repeat the same cycle. ~100s rather than the ~487s a full burst would cost. The fault drop-in is split so the clock shortening now lands after the measurement rather than with the ExecStart override. Co-Authored-By: Claude Opus 5 (1M context) --- .../scenario_localdns_restart_budget.go | 161 ++++++++++++++++-- 1 file changed, 149 insertions(+), 12 deletions(-) diff --git a/e2e/scenario/scenario_localdns_restart_budget.go b/e2e/scenario/scenario_localdns_restart_budget.go index f148f6c8f9d..6c66360867d 100644 --- a/e2e/scenario/scenario_localdns_restart_budget.go +++ b/e2e/scenario/scenario_localdns_restart_budget.go @@ -96,6 +96,9 @@ const ( localdnsFaultFile = "/run/localdns-e2e-fault" localdnsFaultCounter = "/run/localdns-e2e-starts" localdnsFaultDropIn = "/run/systemd/system/localdns.service.d/99-e2e-fault.conf" + // Kept separate from localdnsFaultDropIn so the real-clock measurement can run with the + // shipped timeouts before the matrix speeds them up. + localdnsFastClockDropIn = "/run/systemd/system/localdns.service.d/99-e2e-fastclock.conf" ) // validateLocalDNSRestartBudget asserts that the unit's restart budget terminates each @@ -127,6 +130,18 @@ func validateLocalDNSRestartBudget(ctx context.Context, s *Scenario, faults []lo _, _ = execScriptOnVMForScenario(cleanupCtx, s, localdnsFaultTeardownScript) }() + // Ground truth before anything is sped up: measure one real failure cycle against the + // shipped timeouts and check it fits under the threshold. The margin assertion above is + // arithmetic on a model of the unit; this is the machine's own answer. The matrix below + // runs on shortened clocks and cannot check this. + if err := measureLocalDNSWorstCycle(ctx, s); err != nil { + return err + } + + if err := installLocalDNSFastClocks(ctx, s); err != nil { + return fmt.Errorf("install shortened fault clocks: %w", err) + } + for _, fault := range faults { if err := runLocalDNSFault(ctx, s, fault); err != nil { return err @@ -135,6 +150,100 @@ func validateLocalDNSRestartBudget(ctx context.Context, s *Scenario, faults []lo return nil } +// installLocalDNSFastClocks shortens WatchdogSec and TimeoutStartSec for the matrix. +// +// At their shipped values (60s, and an inherited 90s) the watchdog and hung-start modes +// need ~14 minutes between them to exhaust the burst, which does not fit the VMSS-scoped +// validation budget that TestTimeoutVMSS shares with VM creation. Shortened, the same code +// paths still run -- a real watchdog timeout, a real start timeout, SIGTERM, restart, +// limiter -- on a faster clock. +// +// StartLimitIntervalSec, StartLimitBurst and RestartSec are never touched: they are what is +// under test. The sizing this shortening stops exercising is covered by the margin +// assertion and by measureLocalDNSWorstCycle, both of which run before this. +func installLocalDNSFastClocks(ctx context.Context, s *Scenario) error { + _, err := execScriptOnVMForScenarioValidateExitCode(ctx, s, ` +set -eu +printf '[Service]\nWatchdogSec=10\nTimeoutStartSec=15\n' | sudo tee `+localdnsFastClockDropIn+` >/dev/null +sudo systemctl daemon-reload +echo "shortened fault clocks installed" +`, 0, "failed to install the shortened fault clocks") + return err +} + +// measureLocalDNSWorstCycle times one real restart cycle of the slowest failure mode and +// asserts it fits under the budget's threshold. +// +// This is the design claim checked against reality rather than against the formula. Waiting +// for the full burst would cost ~8 minutes; two consecutive ExecStarts give the cycle +// length, which is the quantity the budget is sized against, in about 100 seconds. +func measureLocalDNSWorstCycle(ctx context.Context, s *Scenario) error { + _, err := execScriptOnVMForScenarioValidateExitCode(ctx, s, localdnsWorstCycleScript, 0, + "LocalDNS worst restart cycle does not fit under the start-limit threshold") + return err +} + +const localdnsWorstCycleScript = ` +set -eu + +usec() { systemd-analyze timespan "$1" 2>/dev/null | sed -n '2s/.*: *//p'; } +interval_us=$(usec "$(systemctl show localdns.service -p StartLimitIntervalUSec --value)") +burst_n=$(systemctl show localdns.service -p StartLimitBurst --value) +threshold_s=$(( interval_us / burst_n / 1000000 )) + +echo "=== measuring the real worst restart cycle (hung start, shipped clocks) ===" +echo "threshold is ${threshold_s}s" + +sudo systemctl stop localdns.service 2>/dev/null || true +sudo systemctl reset-failed localdns.service 2>/dev/null || true +echo hungstart | sudo tee ` + localdnsFaultFile + ` >/dev/null +sudo rm -f ` + localdnsFaultCounter + ` +sudo systemctl start --no-block localdns.service || true + +# Two ExecStarts is all that is needed. Worst case here is TimeoutStartSec 90 + +# TimeoutStopSec 30 + RestartSec 2 = ~122s, so 240s leaves generous headroom. +observed=0 +for i in $(seq 1 240); do + observed=$(sudo grep -c EXECSTART ` + localdnsFaultCounter + ` 2>/dev/null || echo 0) + [ "$observed" -ge 2 ] && break + sleep 1 +done + +# Abort the run: the remaining starts would only repeat the same cycle. +sudo rm -f ` + localdnsFaultFile + ` +sudo systemctl stop localdns.service 2>/dev/null || true +sudo systemctl reset-failed localdns.service 2>/dev/null || true + +if [ "$observed" -lt 2 ]; then + echo "FAIL: only observed $observed ExecStart(s) in 240s; cannot measure a restart cycle" + sudo systemctl status localdns.service --no-pager -l || true + exit 1 +fi + +t1=$(sudo sed -n '1p' ` + localdnsFaultCounter + ` | awk '{print $1}') +t2=$(sudo sed -n '2p' ` + localdnsFaultCounter + ` | awk '{print $1}') +cycle_s=$(( t2 - t1 )) +echo "measured worst restart cycle: ${cycle_s}s (threshold ${threshold_s}s)" + +if [ "$cycle_s" -ge "$threshold_s" ]; then + echo "FAIL: the slowest failure cycle (${cycle_s}s) is not under the threshold (${threshold_s}s)." + echo " A failure on this cycle never accumulates StartLimitBurst starts inside the" + echo " window, so it would restart forever instead of terminating in 'failed'." + exit 1 +fi + +# Leave the service healthy for the matrix that follows. +sudo systemctl start localdns.service +for attempt in 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15; do + sudo systemctl is-active --quiet localdns.service && break + sleep 1 +done +sudo systemctl is-active --quiet localdns.service || { + echo "FAIL: localdns did not recover after the worst-cycle measurement" + exit 1 +} +` + // assertLocalDNSBudgetDirectives checks the effective directives rather than the file, so // a drop-in that quietly overrides them is caught too. func assertLocalDNSBudgetDirectives(ctx context.Context, s *Scenario) error { @@ -173,6 +282,42 @@ check Restart "on-failure" # and silently invalidate the margin. Assert it so that change fails here instead. check TimeoutStartUSec "1min 30s" +# The design rule itself, as arithmetic on the live values rather than on the numbers this +# comment happens to quote. +# +# threshold = StartLimitIntervalSec / StartLimitBurst +# worst cycle = TimeoutStartSec + TimeoutStopSec + RestartSec +# +# A failure repeating more slowly than the threshold never accumulates StartLimitBurst +# starts inside the window, so it restarts forever instead of reaching 'failed' -- exactly +# the behaviour this PR exists to prevent. Checking every input this way means any change +# to the interval, the burst, either timeout, or RestartSec that closes the margin fails +# here, instead of silently shipping a budget that cannot catch the slow modes. +usec() { systemd-analyze timespan "$1" 2>/dev/null | sed -n '2s/.*: *//p'; } + +interval_us=$(usec "$(systemctl show localdns.service -p StartLimitIntervalUSec --value)") +tstart_us=$(usec "$(systemctl show localdns.service -p TimeoutStartUSec --value)") +tstop_us=$(usec "$(systemctl show localdns.service -p TimeoutStopUSec --value)") +restart_us=$(usec "$(systemctl show localdns.service -p RestartUSec --value)") +burst_n=$(systemctl show localdns.service -p StartLimitBurst --value) + +if [ -z "$interval_us" ] || [ -z "$tstart_us" ] || [ -z "$tstop_us" ] || [ -z "$restart_us" ] \ + || [ -z "$burst_n" ] || [ "$burst_n" -le 0 ] 2>/dev/null; then + echo "FAIL: could not read the restart-budget inputs needed for the margin check" + echo " interval=[$interval_us] burst=[$burst_n] tstart=[$tstart_us] tstop=[$tstop_us] restart=[$restart_us]" + fail=1 +else + threshold_us=$(( interval_us / burst_n )) + worst_us=$(( tstart_us + tstop_us + restart_us )) + echo "margin: threshold $((threshold_us/1000000))s vs worst cycle $((worst_us/1000000))s" + if [ "$threshold_us" -le "$worst_us" ]; then + echo "FAIL: threshold $((threshold_us/1000000))s does not clear the worst restart cycle $((worst_us/1000000))s" + echo " (TimeoutStartSec $((tstart_us/1000000))s + TimeoutStopSec $((tstop_us/1000000))s + RestartSec $((restart_us/1000000))s)" + echo " A failure on that cycle would restart forever rather than terminate in 'failed'." + fail=1 + fi +fi + if [ "$fail" -ne 0 ]; then echo echo "localdns.service is baked into the VHD (vhdbuilder/packer/packer_source.sh), not" @@ -387,17 +532,9 @@ rm -rf "$WORK" # Point the unit at the patched copy. Invoking through bash avoids any noexec concern on # /run. ExecStart= clears the shipped value before setting the replacement. sudo mkdir -p "$(dirname "$DROPIN")" -# Shorten the two unit-level clocks for the duration of the fault run. WatchdogSec and -# TimeoutStartSec drive how long the watchdog and hung-start modes take to cycle: at their -# shipped values (60s and an inherited 90s) those two modes alone need ~14 minutes to -# exhaust the burst, which does not fit the VMSS-scoped validation budget (TestTimeoutVMSS, -# shared with VM creation). Shortened, the same code paths run -- a real watchdog timeout, a -# real start timeout, SIGTERM, restart, limiter -- just on a faster clock. -# -# StartLimitIntervalSec, StartLimitBurst and RestartSec are deliberately NOT touched: they -# are what is under test. Note this does mean the matrix validates the mechanism rather than -# the shipped durations; the real timings are measured separately and recorded on the PR. -printf '[Service]\nExecStart=\nExecStart=/bin/bash %s\nWatchdogSec=10\nTimeoutStartSec=15\n' "$DST" | sudo tee "$DROPIN" >/dev/null +# ExecStart only. The clock shortening lives in a separate drop-in installed later, so the +# real-clock worst-cycle measurement can run against the shipped timeouts first. +printf '[Service]\nExecStart=\nExecStart=/bin/bash %s\n' "$DST" | sudo tee "$DROPIN" >/dev/null sudo systemctl daemon-reload echo "fault harness installed" ` @@ -406,7 +543,7 @@ echo "fault harness installed" // best-effort by design: it runs from a defer, including on the failure path. const localdnsFaultTeardownScript = ` set -u -sudo rm -f ` + localdnsFaultFile + ` ` + localdnsFaultCounter + ` ` + localdnsFaultDropIn + ` ` + localdnsFaultScript + ` +sudo rm -f ` + localdnsFaultFile + ` ` + localdnsFaultCounter + ` ` + localdnsFaultDropIn + ` ` + localdnsFastClockDropIn + ` ` + localdnsFaultScript + ` sudo systemctl daemon-reload || true sudo systemctl reset-failed localdns.service || true sudo systemctl start localdns.service || true From fb79777a2d04e0d488ca4d40628b9d1b610066ff Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Fri, 18 Sep 2026 06:36:30 +0000 Subject: [PATCH 16/26] fix: reap the watchdog sleep on SIGTERM, and test the invariants properly Three review items. 1. The backgrounded watchdog sleep was never reaped. SIGTERM was untrapped, so bash died on the default action: the EXIT cleanup never ran, and the sleep survived as an orphan in the unit's cgroup. With KillMode=mixed systemd signals only the main process, so it then held the unit in stop-sigterm until the sleep finished on its own (up to HEALTH_CHECK_INTERVAL) or TimeoutStopSec expired and it was SIGKILLed -- delaying the stop, and with it the next start, which is the opposite of what RestartSec=2 is for. Trap SIGTERM, kill and wait on the child via a named stop_watchdog_sleep, and exit 0 because a requested stop is not a failure and Restart=on-failure must not fire for it. 2. That path had no coverage. Added tests using real processes and real signals rather than mocks: a mocked kill would prove nothing about whether the child actually goes away. Verified by deleting the kill and watching the test fail with "child N survived stop_watchdog_sleep". The first version of that test was itself broken -- it checked WATCHDOG_SLEEP_PID after stop_watchdog_sleep had cleared it, so it was evaluating 'kill -0 ""' and passed even with the kill removed. It now saves the pid first. 3. The reset-failed spec only proved both calls appeared somewhere, so hoisting reset-failed out of the retry loop would still have passed. It now records an ordered trace and asserts RSRSRS across two failed restarts and a success, and asserts the give-up path ends on a start attempt rather than a reset, so the unit is left in 'failed' for NPD. Verified by hoisting the call and watching it fail. Co-Authored-By: Claude Opus 5 (1M context) --- parts/linux/cloud-init/artifacts/localdns.sh | 34 ++++++++-- .../artifacts/cse_config_localdns_spec.sh | 42 +++++++++--- .../cloud-init/artifacts/localdns_spec.sh | 67 +++++++++++++++++++ 3 files changed, 131 insertions(+), 12 deletions(-) diff --git a/parts/linux/cloud-init/artifacts/localdns.sh b/parts/linux/cloud-init/artifacts/localdns.sh index 8e8aefd82a5..365a610b08b 100644 --- a/parts/linux/cloud-init/artifacts/localdns.sh +++ b/parts/linux/cloud-init/artifacts/localdns.sh @@ -883,6 +883,23 @@ export_resource_metrics() { # The health check is a DNS request to the localdns service IPs. # The health check is run at 20% of the WATCHDOG_USEC interval. # If the health check fails, the script will exit and systemd will restart the service. +# Kill the backgrounded watchdog sleep, if one is in flight. +# +# start_localdns_watchdog waits by backgrounding 'sleep' and waiting on it, so that a +# signal can interrupt the wait rather than being deferred until the sleep returns. With +# KillMode=mixed systemd sends SIGTERM to this script only, so without killing the child +# explicitly the sleep survives as an orphan in the unit's cgroup: systemd then holds the +# unit in stop-sigterm until the sleep finishes on its own (up to HEALTH_CHECK_INTERVAL) +# or TimeoutStopSec expires and it is SIGKILLed -- delaying the stop, and with it the +# next start. +stop_watchdog_sleep() { + if [ -n "${WATCHDOG_SLEEP_PID:-}" ]; then + kill "${WATCHDOG_SLEEP_PID}" 2>/dev/null || true + wait "${WATCHDOG_SLEEP_PID}" 2>/dev/null || true + WATCHDOG_SLEEP_PID="" + fi +} + start_localdns_watchdog() { if [ -n "${NOTIFY_SOCKET:-}" ] && [ -n "${WATCHDOG_USEC:-}" ]; then # Health check at 20% of WATCHDOG_USEC; this means that we should check. @@ -937,11 +954,14 @@ start_localdns_watchdog() { # Update resource metrics .prom file for the exporter (best-effort, non-fatal) export_resource_metrics - # Wait for the next watchdog interval. Run sleep in a child so - # SIGTERM can interrupt the wait and let the service's signal/exit - # cleanup run promptly. + # Wait for the next watchdog interval. Run sleep in a child so SIGTERM can + # interrupt the wait and let the service's signal/exit cleanup run promptly. + # The pid is recorded so the SIGTERM handler can reap the child instead of + # leaving it in the cgroup holding the unit's stop open. sleep "${HEALTH_CHECK_INTERVAL}" & - wait $! + WATCHDOG_SLEEP_PID=$! + wait "${WATCHDOG_SLEEP_PID}" + WATCHDOG_SLEEP_PID="" done else # No watchdog configured — write metrics once then wait for CoreDNS to exit @@ -1084,6 +1104,12 @@ build_localdns_iptable_rules trap 'echo "Error occurred. Cleaning up..."; cleanup_localdns_configs; exit $ERR_LOCALDNS_FAIL' ABRT ERR INT PIPE # Always cleanup when exiting. +# SIGTERM is how systemd stops this unit. It was previously untrapped, so bash died on the +# default action: the EXIT cleanup below never ran, and any in-flight watchdog sleep was +# left orphaned in the cgroup. Handle it so the child is reaped and cleanup runs. Exit 0 +# because a requested stop is not a failure -- Restart=on-failure must not fire for it. +trap 'echo "Received SIGTERM, shutting down."; stop_watchdog_sleep; exit 0' TERM + trap 'echo "Executing cleanup function."; cleanup_localdns_configs || echo "Cleanup failed with error code: $ERR_LOCALDNS_FAIL."' EXIT # Configure interface listening on Node listener and cluster listener IPs. diff --git a/spec/parts/linux/cloud-init/artifacts/cse_config_localdns_spec.sh b/spec/parts/linux/cloud-init/artifacts/cse_config_localdns_spec.sh index d9c8a104003..cba34720f88 100755 --- a/spec/parts/linux/cloud-init/artifacts/cse_config_localdns_spec.sh +++ b/spec/parts/linux/cloud-init/artifacts/cse_config_localdns_spec.sh @@ -107,24 +107,50 @@ Describe 'cse_config_localdns.sh' The output should not include "localdns should be enabled." End - It 'should clear the StartLimit budget before each start attempt' + # Record an ordered trace of the calls that matter: R for reset-failed, S for a + # start attempt. Asserting on the trace is what pins "before *each* attempt" -- a + # test that only checks both strings appear somewhere would still pass if + # reset-failed were hoisted out of the loop. + tracing_systemctl() { + systemctl() { + case "$1" in + reset-failed) printf 'R' >> "$TMP_DIR/trace" ;; + restart) printf 'S' >> "$TMP_DIR/trace" ;; + esac + echo "systemctl $*" + if [ "$1" = "restart" ]; then + restart_calls=$((restart_calls + 1)) + if [ "$restart_calls" -lt "$restart_failures_before_success" ]; then + return 1 + fi + fi + return 0 + } + restart_calls=0 + } + + It 'should reset the StartLimit budget before every attempt, not only the first' + # Two failed restarts then a success, so the loop runs three times. + restart_failures_before_success=3 + tracing_systemctl When run enableLocalDNS The status should be success - The output should include "systemctl reset-failed localdns" - The output should include "systemctl restart localdns" The output should include "Enable localdns succeeded." + # R before every S, three times over -- not RSSS. + The contents of file "$TMP_DIR/trace" should equal "RSRSRS" End It 'should return error when systemctl fails to start localdns' - systemctl() { - echo "systemctl $*" - [ "$1" = "restart" ] && return 1 - return 0 - } + # Never succeeds, so the loop exhausts and takes the give-up path. + restart_failures_before_success=99999 + tracing_systemctl When run enableLocalDNS The status should equal 216 The output should include "localdns should be enabled." The output should include "systemctl reset-failed localdns" + # The give-up path deliberately does not reset, so the unit is left in 'failed' + # for NPD: the trace must end on a start attempt, never on a reset. + The contents of file "$TMP_DIR/trace" should end with "S" End End Describe 'enableLocalDNSForScriptless' diff --git a/spec/parts/linux/cloud-init/artifacts/localdns_spec.sh b/spec/parts/linux/cloud-init/artifacts/localdns_spec.sh index cc231860374..9b3bb321af6 100644 --- a/spec/parts/linux/cloud-init/artifacts/localdns_spec.sh +++ b/spec/parts/linux/cloud-init/artifacts/localdns_spec.sh @@ -1348,6 +1348,73 @@ EOF End End +# This section tests - stop_watchdog_sleep +# This function is defined in parts/linux/cloud-init/artifacts/localdns.sh file. +# +# The watchdog waits by backgrounding 'sleep' so a signal can interrupt the wait. With +# KillMode=mixed systemd signals only the main process, so the child has to be reaped +# explicitly or it holds the unit's cgroup open and delays the stop. These use real +# processes and real signals rather than mocks -- a mocked kill would prove nothing about +# whether the child actually goes away. +#------------------------------------------------------------------------------------------------------------------------------------ + Describe 'stop_watchdog_sleep' + setup() { + Include "./parts/linux/cloud-init/artifacts/localdns.sh" + } + BeforeEach 'setup' + + It 'should kill an in-flight watchdog sleep' + start_and_stop_sleep() { + sleep 300 & + WATCHDOG_SLEEP_PID=$! + # Keep our own copy: stop_watchdog_sleep clears WATCHDOG_SLEEP_PID, so + # checking that variable afterwards would test 'kill -0 ""' and pass even + # if the child were still alive. + child_pid=$WATCHDOG_SLEEP_PID + # the child must genuinely be running before we try to stop it + kill -0 "$child_pid" 2>/dev/null || { echo "child never started"; return 1; } + stop_watchdog_sleep + # and genuinely gone afterwards + if kill -0 "$child_pid" 2>/dev/null; then + echo "child $child_pid survived stop_watchdog_sleep" + kill -9 "$child_pid" 2>/dev/null + return 1 + fi + echo "child reaped" + return 0 + } + When call start_and_stop_sleep + The status should be success + The output should include "child reaped" + End + + It 'should clear the recorded pid so a second call is a no-op' + stop_twice() { + sleep 300 & + WATCHDOG_SLEEP_PID=$! + stop_watchdog_sleep + [ -z "${WATCHDOG_SLEEP_PID}" ] || { echo "pid not cleared"; return 1; } + # calling again with nothing in flight must not error + stop_watchdog_sleep + echo "second call was a no-op" + } + When call stop_twice + The status should be success + The output should include "second call was a no-op" + End + + It 'should do nothing when no sleep is in flight' + no_sleep() { + WATCHDOG_SLEEP_PID="" + stop_watchdog_sleep + echo "no-op ok" + } + When call no_sleep + The status should be success + The output should include "no-op ok" + End + End + # This section tests - wait_for_localdns_removed_from_resolv_conf # This function is defined in parts/linux/cloud-init/artifacts/localdns.sh file. From 4326b8b231b027bca59eb2d70b42419da585ba3d Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Fri, 18 Sep 2026 17:18:50 +0000 Subject: [PATCH 17/26] fix: pin TimeoutStartSec so the restart-budget margin is distro-independent The 720/5 threshold (144s) is sized to clear the slowest restart cycle, TimeoutStartSec + TimeoutStopSec + RestartSec. Two of those three were pinned by the unit and the third was inherited from the manager default -- which is a systemd build-time constant (-Ddefault-timeout-sec), not a constant across the images we ship. Ubuntu builds it at 90s; Azure Linux 3.0 builds it at 45s. So the worst cycle, and therefore the margin under the threshold, was silently different per distro: 122s on Ubuntu, 77s on Azure Linux. Both clear 144s today, so this is not a live defect, but the margin the unit documents was never actually the unit's to guarantee, and a change to DefaultTimeoutStartSec on any image would move it with nothing to catch that. Pin it at 90 so the arithmetic in the comment above is self-contained. This also makes the e2e assertion honest. It checks TimeoutStartUSec="1min 30s", which passed on Ubuntu and failed on AzureLinuxV3 with "got 45s" -- correctly reporting a real difference, but one no image was ever going to satisfy uniformly while the value was inherited. Co-Authored-By: Claude Opus 5 (1M context) --- parts/linux/cloud-init/artifacts/localdns.service | 10 +++++++++- 1 file changed, 9 insertions(+), 1 deletion(-) diff --git a/parts/linux/cloud-init/artifacts/localdns.service b/parts/linux/cloud-init/artifacts/localdns.service index a36b7dde3c7..b5f313fc824 100644 --- a/parts/linux/cloud-init/artifacts/localdns.service +++ b/parts/linux/cloud-init/artifacts/localdns.service @@ -10,7 +10,8 @@ ConditionKernelVersion=>=5.15 # Bound the restart budget so every unrecoverable failure mode terminates in # 'failed' rather than restarting forever. The threshold is # StartLimitIntervalSec/StartLimitBurst = 720/5 = 144s, just above the slowest -# restart cycle (~125s = TimeoutStartSec 90 + TimeoutStopSec 30 + RestartSec 2), +# restart cycle (~125s = TimeoutStartSec 90 + TimeoutStopSec 30 + RestartSec 2, +# all three pinned below so the margin does not depend on manager defaults), # so slow failures (PID file never appears, watchdog kill, ready-check timeout, # hung start) still reach 'failed'. That terminal state is what lets an # OnFailure= handoff fire and gives NPD a stable state to observe. @@ -44,6 +45,13 @@ RestartSec=2 KillMode=mixed # Revert node DNS configuration even when the supervisor exits unexpectedly. ExecStopPost=/opt/azure/containers/localdns/localdns.sh cleanup +# Pinned, not inherited, so the StartLimit margin above is self-contained. The +# manager default is a systemd build-time constant (-Ddefault-timeout-sec) and it +# is not the same on every image we ship: Ubuntu builds it at 90s, Azure Linux at +# 45s. Leaving it inherited makes the slowest restart cycle -- and therefore the +# margin under the 144s threshold -- differ per distro, and a change to +# DefaultTimeoutStartSec would move it silently. +TimeoutStartSec=90 TimeoutStopSec=30 Slice=localdns.slice EnvironmentFile=-/etc/localdns/environment From 32e643242544c6ce62147a2a07a02f35f6feebad Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Fri, 18 Sep 2026 17:19:13 +0000 Subject: [PATCH 18/26] test(e2e): fix the hung-start clock, and skip the budget check on older VHDs Two independent failures from the check-in gate on fb79777a2 (build 181710671). 1. hungstart timed out at its deadline with execstarts=3, sub=stop-sigterm. installLocalDNSFastClocks shortened TimeoutStartSec 90->15 but left TimeoutStopSec at 30, so each cycle is 15+30+2 = 47s rather than the ~22s the deadline was sized for. Five of those do not fit 120s; the run gave up mid-cycle three. The stop phase is consumed in full because of the TERM trap added in fb79777a2. The fault holds a foreground 'sleep infinity', and bash defers a trapped signal until the foreground child returns, so nothing answers the SIGTERM and systemd waits out TimeoutStopSec before the SIGKILL. Untrapped -- which is what the by-hand matrix on the PR measured -- bash died immediately and the stop phase cost ~6s, which is why that run recorded 487s for a mode that now costs ~625s shipped. Nothing in localdns.sh blocks that way in production: the watchdog uses 'sleep & wait', which the trap does interrupt. Shorten TimeoutStopSec to 5 alongside the other two clocks. Cycle returns to 22s, the mode terminates in ~110s, and the deadline goes to 180s for real slack. Nothing that reads TimeoutStopSec runs after this point -- the margin assertion and measureLocalDNSWorstCycle both run before the fast clocks install -- so no coverage is lost. 2. The directive assertion cannot pass on the non-gate e2e lane. localdns.service is baked into the VHD, so the budget only exists on an image built from a branch carrying it. The check-in gate builds this PR's images, but .pipelines/e2e.yaml also triggers on any PR touching e2e/** and resolves images by branch=refs/heads/main, which still ship the systemd default. Build 181710682 failed all three distros with "expected StartLimitIntervalUSec=12min, got 10s" -- an accurate reading of an image that was never meant to carry it. Probe StartLimitIntervalUSec up front and skip when it is absent, the way validateLocalDNSLifecycle already skips its dead-service block on images predating the ExecStopPost hook. The interval is the right probe because it is unambiguous provenance; TimeoutStartUSec now reads 1min 30s on new images and on older Ubuntu ones alike. Also carries the comment update matching the TimeoutStartSec pin. Co-Authored-By: Claude Opus 5 (1M context) --- .../scenario_localdns_restart_budget.go | 100 ++++++++++++++---- 1 file changed, 81 insertions(+), 19 deletions(-) diff --git a/e2e/scenario/scenario_localdns_restart_budget.go b/e2e/scenario/scenario_localdns_restart_budget.go index 6c66360867d..33621fd417e 100644 --- a/e2e/scenario/scenario_localdns_restart_budget.go +++ b/e2e/scenario/scenario_localdns_restart_budget.go @@ -3,7 +3,10 @@ package scenario import ( "context" "fmt" + "strings" "time" + + "github.com/Azure/agentbaker/e2e/logging" ) // LocalDNS restart-budget validation. @@ -58,7 +61,7 @@ type localdnsFault struct { // mode shipped shortened by // readytimeout 318s wait_for_localdns_ready args 60/60 -> 8/8 // watchdog 370s WatchdogSec 60 -> 10 -// hungstart 487s TimeoutStartSec 90 -> 15 +// hungstart 625s TimeoutStartSec 90 -> 15, TimeoutStopSec 30 -> 5 var localdnsFaultMatrix = []localdnsFault{ {name: "preflight", label: "pre-flight abort", deadlineSeconds: 45}, // ~11s {name: "resolvdrain", label: "resolv.conf never drains", deadlineSeconds: 80}, // ~37s @@ -66,7 +69,7 @@ var localdnsFaultMatrix = []localdnsFault{ {name: "nopidfile", label: "PID file never appears", deadlineSeconds: 90}, // ~30s shortened {name: "readytimeout", label: "ready-check timeout", deadlineSeconds: 120}, // ~75s shortened {name: "watchdog", label: "watchdog pings cease", deadlineSeconds: 120}, // ~90s shortened - {name: "hungstart", label: "hung start", deadlineSeconds: 120}, // ~90s shortened + {name: "hungstart", label: "hung start", deadlineSeconds: 180}, // ~110s shortened } // localdnsDiscriminatingFault is the single mode used on distros that do not carry the @@ -99,6 +102,9 @@ const ( // Kept separate from localdnsFaultDropIn so the real-clock measurement can run with the // shipped timeouts before the matrix speeds them up. localdnsFastClockDropIn = "/run/systemd/system/localdns.service.d/99-e2e-fastclock.conf" + // StartLimitIntervalSec=720 as systemd formats it. Shared by the provenance probe and + // the directive assertion so the two cannot drift apart. + localdnsExpectedStartLimitInterval = "12min" ) // validateLocalDNSRestartBudget asserts that the unit's restart budget terminates each @@ -108,6 +114,14 @@ func validateLocalDNSRestartBudget(ctx context.Context, s *Scenario, faults []lo return fmt.Errorf("no LocalDNS faults selected: the fault matrix is misconfigured") } + carries, err := vhdCarriesLocalDNSRestartBudget(ctx, s) + if err != nil { + return err + } + if !carries { + return nil + } + if err := assertLocalDNSBudgetDirectives(ctx, s); err != nil { return err } @@ -150,13 +164,24 @@ func validateLocalDNSRestartBudget(ctx context.Context, s *Scenario, faults []lo return nil } -// installLocalDNSFastClocks shortens WatchdogSec and TimeoutStartSec for the matrix. +// installLocalDNSFastClocks shortens WatchdogSec, TimeoutStartSec and TimeoutStopSec for the +// matrix. // -// At their shipped values (60s, and an inherited 90s) the watchdog and hung-start modes -// need ~14 minutes between them to exhaust the burst, which does not fit the VMSS-scoped -// validation budget that TestTimeoutVMSS shares with VM creation. Shortened, the same code -// paths still run -- a real watchdog timeout, a real start timeout, SIGTERM, restart, -// limiter -- on a faster clock. +// At their shipped values (60s, 90s and 30s) the watchdog and hung-start modes need ~16 +// minutes between them to exhaust the burst, which does not fit the VMSS-scoped validation +// budget that TestTimeoutVMSS shares with VM creation. Shortened, the same code paths still +// run -- a real watchdog timeout, a real start timeout, SIGTERM, restart, limiter -- on a +// faster clock. +// +// TimeoutStopSec is shortened for a non-obvious reason: hung-start spends its stop phase in +// full. The fault holds a foreground 'sleep infinity', and localdns.sh now traps TERM, so +// bash queues the handler until the foreground child returns -- which it never does. Nothing +// answers the SIGTERM and systemd waits out TimeoutStopSec before SIGKILLing the cgroup on +// every cycle. Before the TERM trap existed an untrapped SIGTERM killed bash immediately and +// the stop phase cost ~6s, which is why the by-hand measurement recorded on the PR (487s) +// is lower than what this now costs shipped (~625s). At 30s the shortened cycle is 47s and +// five of them do not fit any sane deadline; at 5s it is 22s, which is what the matrix's +// hungstart deadline is sized against. // // StartLimitIntervalSec, StartLimitBurst and RestartSec are never touched: they are what is // under test. The sizing this shortening stops exercising is covered by the margin @@ -164,7 +189,7 @@ func validateLocalDNSRestartBudget(ctx context.Context, s *Scenario, faults []lo func installLocalDNSFastClocks(ctx context.Context, s *Scenario) error { _, err := execScriptOnVMForScenarioValidateExitCode(ctx, s, ` set -eu -printf '[Service]\nWatchdogSec=10\nTimeoutStartSec=15\n' | sudo tee `+localdnsFastClockDropIn+` >/dev/null +printf '[Service]\nWatchdogSec=10\nTimeoutStartSec=15\nTimeoutStopSec=5\n' | sudo tee `+localdnsFastClockDropIn+` >/dev/null sudo systemctl daemon-reload echo "shortened fault clocks installed" `, 0, "failed to install the shortened fault clocks") @@ -244,6 +269,42 @@ sudo systemctl is-active --quiet localdns.service || { } ` +// vhdCarriesLocalDNSRestartBudget reports whether the image under test actually ships the +// restart budget, so an image that predates it is skipped rather than failed. +// +// localdns.service is baked into the VHD (vhdbuilder/packer/packer_source.sh), not delivered +// through CustomData, so these directives only exist on an image built from a branch that +// carries them. Two e2e lanes run against this repo and they do not agree on which image +// that is: the VHD check-in gate builds this PR's own images and tests them, but +// .pipelines/e2e.yaml also triggers on any PR touching e2e/**, and it resolves images by +// branch=refs/heads/main -- which legitimately still ship the systemd default 10s/5 budget. +// Asserting unconditionally makes that second lane permanently red for any PR that changes +// this file, and the failure says "the directives were removed" about an image that was +// never meant to have them. +// +// StartLimitIntervalUSec is the probe rather than any other directive because it is +// unambiguous provenance: 12min exists only on an image carrying this change, and the 10s +// default identifies an older one. TimeoutStartUSec cannot be used -- it now reads 1min 30s +// on new images but also on any older Ubuntu image, so it does not separate them. +// +// This mirrors validateLocalDNSLifecycle, which already skips its terminal dead-service +// block on images predating the ExecStopPost cleanup hook. +func vhdCarriesLocalDNSRestartBudget(ctx context.Context, s *Scenario) (bool, error) { + result, err := execScriptOnVMForScenario(ctx, s, + `systemctl show localdns.service -p StartLimitIntervalUSec --value`) + if err != nil { + return false, fmt.Errorf("read the LocalDNS start-limit interval: %w", err) + } + interval := strings.TrimSpace(result.stdout) + if interval != localdnsExpectedStartLimitInterval { + logging.Logf(ctx, "SKIP: VHD predates the LocalDNS restart budget (StartLimitIntervalUSec=%q, want %q); "+ + "this image is not built from a branch carrying localdns.service's budget", + interval, localdnsExpectedStartLimitInterval) + return false, nil + } + return true, nil +} + // assertLocalDNSBudgetDirectives checks the effective directives rather than the file, so // a drop-in that quietly overrides them is caught too. func assertLocalDNSBudgetDirectives(ctx context.Context, s *Scenario) error { @@ -265,7 +326,7 @@ check() { } # The budget under test. -check StartLimitIntervalUSec "12min" +check StartLimitIntervalUSec "` + localdnsExpectedStartLimitInterval + `" check StartLimitBurst "5" check RestartUSec "2s" @@ -277,9 +338,10 @@ check RestartUSec "2s" check Restart "on-failure" # The threshold is StartLimitIntervalSec/StartLimitBurst = 720/5 = 144s, which only clears -# the slowest restart cycle while TimeoutStartSec stays at the inherited 90s. It is not -# pinned in the unit, so a change to DefaultTimeoutStartSec would move the slowest cycle -# and silently invalidate the margin. Assert it so that change fails here instead. +# the slowest restart cycle at TimeoutStartSec=90s. That is pinned in the unit rather than +# inherited, because the manager default is a systemd build-time constant that differs by +# image -- Ubuntu builds it at 90s, Azure Linux at 45s -- so an inherited value made the +# margin, and this assertion, distro-dependent. Assert the pin so dropping it fails here. check TimeoutStartUSec "1min 30s" # The design rule itself, as arithmetic on the live values rather than on the numbers this @@ -324,13 +386,13 @@ if [ "$fail" -ne 0 ]; then echo "delivered through CustomData, so these directives only exist on an image built" echo "from a branch that carries them." echo - echo "If you are running e2e locally, the default is SIG_VERSION_TAG_VALUE=refs/heads/main," - echo "which pulls a main-built image -- that image legitimately has the old 10s/5/100ms" - echo "budget and this failure is expected. Re-run against the PR's VHD build instead:" - echo " VHD_BUILD_ID= ./e2e-local.sh " + echo "Reaching this message means the image DOES carry the budget -- vhdCarriesLocalDNSRestartBudget" + echo "already matched StartLimitIntervalUSec and would have skipped an older image before" + echo "getting here. So one of the other directives was removed, overridden by a drop-in," + echo "or is inherited on this distro when it should be pinned." echo - echo "In PR CI this runs against the PR's own VHD build, so a failure here means the" - echo "directives were actually removed or overridden." + echo "Note TimeoutStartUSec is pinned by the unit precisely because the manager default is" + echo "a systemd build-time constant: Ubuntu builds it at 90s, Azure Linux at 45s." fi exit "$fail" From fbe622a10894c4287e893a61dcbc2d3341396f22 Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Fri, 18 Sep 2026 21:38:50 +0000 Subject: [PATCH 19/26] fix: pin TimeoutStopFailureMode so the restart margin holds by design The 720/5 threshold (144s) is sized against TimeoutStartSec + TimeoutStopSec + RestartSec. Pinning the start timeout at 90 (previous commit, per review) pushed AzureLinuxV3 to a measured 153s -- above the threshold, meaning the slow failure modes would restart forever there, which is the bug this budget exists to prevent. The stop side is doubled on that distro. Azure Linux ships a global drop-in, /usr/lib/systemd/system/service.d/10-timeout-abort.conf, setting TimeoutStopFailureMode=abort (Fedora's "Shorter Shutdown Timer"). On a stop timeout systemd sends SIGABRT to capture a core dump, then waits a SECOND TimeoutStopSec in 'stop-watchdog' before SIGKILL. From the node's journal: 18:51:49 start operation timed out. Terminating. <- SIGTERM 18:52:19 State 'stop-sigterm' timed out. Aborting. <- +30s, SIGABRT 18:52:49 State 'stop-watchdog' timed out. Killing. <- +30s, SIGKILL 18:52:50 ExecStopPost done (1s), Failed with result 'timeout' 18:52:52 restart 90 + 30 + 30 + 1 + 2 = 153s, against the measured 153s. Before the start timeout was pinned this did not show, because Azure Linux also builds systemd with -Ddefault-timeout-sec=45: 45 + 60 + 2 = 108s stayed under 144. The margin was holding on a coincidence -- a shorter start timeout cancelling a doubled stop timeout -- on one distro, undocumented either way. Pin 'terminate' (the systemd default) so the distro's drop-in is out of the cycle and every image is 90 + 30 + 2 = 122s. The core dump the abort step exists to produce is already discarded on AKS nodes: configureCoreDump() in cis.sh sets Storage=none and ProcessSizeMax=0 for every distro, asserted by testCoreDumpSettings in linux-vhd-content-test.sh. Today that step costs 30s of restart cycle and produces nothing. The unit comment records that dependency and says to revisit this if the hardening is ever relaxed. Co-Authored-By: Claude Opus 5 (1M context) --- .../cloud-init/artifacts/localdns.service | 26 +++++++++++++++++-- 1 file changed, 24 insertions(+), 2 deletions(-) diff --git a/parts/linux/cloud-init/artifacts/localdns.service b/parts/linux/cloud-init/artifacts/localdns.service index b5f313fc824..b469e350453 100644 --- a/parts/linux/cloud-init/artifacts/localdns.service +++ b/parts/linux/cloud-init/artifacts/localdns.service @@ -10,8 +10,9 @@ ConditionKernelVersion=>=5.15 # Bound the restart budget so every unrecoverable failure mode terminates in # 'failed' rather than restarting forever. The threshold is # StartLimitIntervalSec/StartLimitBurst = 720/5 = 144s, just above the slowest -# restart cycle (~125s = TimeoutStartSec 90 + TimeoutStopSec 30 + RestartSec 2, -# all three pinned below so the margin does not depend on manager defaults), +# restart cycle (~122s = TimeoutStartSec 90 + TimeoutStopSec 30 + RestartSec 2, all +# pinned below -- including TimeoutStopFailureMode, without which Azure Linux spends two +# stop timeouts and the cycle is 153s, above the threshold), # so slow failures (PID file never appears, watchdog kill, ready-check timeout, # hung start) still reach 'failed'. That terminal state is what lets an # OnFailure= handoff fire and gives NPD a stable state to observe. @@ -53,6 +54,27 @@ ExecStopPost=/opt/azure/containers/localdns/localdns.sh cleanup # DefaultTimeoutStartSec would move it silently. TimeoutStartSec=90 TimeoutStopSec=30 +# Pinned for the same reason, and measured rather than assumed. Azure Linux ships a global +# drop-in at /usr/lib/systemd/system/service.d/10-timeout-abort.conf setting +# TimeoutStopFailureMode=abort (Fedora's "Shorter Shutdown Timer"): on a stop timeout systemd +# sends SIGABRT to capture a core dump, then waits a SECOND TimeoutStopSec in 'stop-watchdog' +# before SIGKILL. That doubles the stop side of the restart cycle. Measured on AzureLinuxV3: +# 90 + 30 + 30 + 2 = 153s, above the 144s threshold -- so the slow modes would restart forever +# there, which is exactly what this budget exists to prevent. 'terminate' is the systemd +# default; pinning it makes the cycle 90 + 30 + 2 = 122s on every image we ship. +# +# The core dump that step exists to produce is already discarded on AKS nodes: +# configureCoreDump() in parts/linux/cloud-init/artifacts/cis.sh sets Storage=none and +# ProcessSizeMax=0, applied to every distro (it runs before the Mariner/AzureLinux early +# return in applyCIS), and asserted by testCoreDumpSettings in +# vhdbuilder/packer/test/linux-vhd-content-test.sh. So today the abort step costs 30s of +# restart cycle and produces nothing. +# +# If that hardening is ever relaxed -- Storage= set to anything but none, or ProcessSizeMax +# raised -- revisit this directive. The abort step would start producing a usable dump, and +# the 30s it costs would have to be bought back elsewhere in the cycle or the threshold +# widened, or Azure Linux goes back over 144s. +TimeoutStopFailureMode=terminate Slice=localdns.slice EnvironmentFile=-/etc/localdns/environment ExecStart=/opt/azure/containers/localdns/localdns.sh From be8e8ffea63672744fe4238c167124929ce2d66c Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Fri, 18 Sep 2026 21:38:50 +0000 Subject: [PATCH 20/26] test(e2e): gate the LocalDNS validations on the lane, not the unit under test Three review fixes on the restart-budget validation. 1. The provenance guard was self-defeating. It skipped unless StartLimitIntervalUSec was 12min -- the same value the directive assertion then checks -- so that assertion could only run where it was already guaranteed to pass, and sharing a constant between the two made it structural rather than incidental. Worse, a later retune (720 -> 600) would have skipped every lane, gone green on all distros, and said nothing about the budget no longer being tested. Gate on the lane instead. The check-in gate sets SIG_VERSION_TAG_NAME=buildId from VHD_BUILD_ID (.pipelines/scripts/e2e_run.sh) and tests this PR's VHDs; everything else falls back to branch=refs/heads/main, which resolves a main-built image that legitimately predates the budget. Skip only that case, and assert unconditionally otherwise, so the assertion is falsifiable again. validateLocalDNSLifecycle had the identical shape -- probing ExecStopPost to decide whether to test ExecStopPost -- so it now takes the same lane gate and asserts the hook is present rather than using its presence as permission to look. 2. Assert TimeoutStopFailureMode. The margin arithmetic models the stop side as one TimeoutStopSec and cannot see the abort state Azure Linux's global drop-in introduces, so without this it keeps reporting a comfortable 122s while the machine sits at 153s. That is exactly what happened. 3. Size the matrix against TestTimeoutVMSS at build time. Going over budget does not fail like a sizing error: the VMSS context deadline pre-empts the per-fault deadline, so instead of "hung start did not terminate within 180s" -- the diagnostic all this sizing exists to produce -- you get a generic scenario timeout. TestLocalDNSFaultMatrixFitsVMSSBudget now fails the build when it stops fitting. The model is a healthy run plus one regression (allowance + worst-cycle ceiling + sum(measured) + max(deadline - measured)), not every deadline firing at once: a mode only costs its deadline when broken, and the first broken mode aborts the run. Measured times move from comments into the matrix as data so the test can use them. The worst-cycle poll ceiling drops 240s -> 180s, just above the 122s cycle it waits for, and the stale "~23min" note on the Ubuntu2404 selection is corrected -- it described shipped clocks and was never true after the shortening. Co-Authored-By: Claude Opus 5 (1M context) --- e2e/scenario/scenario_localdns_hosts.go | 33 ++++- .../scenario_localdns_restart_budget.go | 134 ++++++++++-------- .../scenario_localdns_restart_budget_test.go | 94 ++++++++++++ 3 files changed, 193 insertions(+), 68 deletions(-) create mode 100644 e2e/scenario/scenario_localdns_restart_budget_test.go diff --git a/e2e/scenario/scenario_localdns_hosts.go b/e2e/scenario/scenario_localdns_hosts.go index 9d9f52e61db..07d4764d7ed 100644 --- a/e2e/scenario/scenario_localdns_hosts.go +++ b/e2e/scenario/scenario_localdns_hosts.go @@ -60,10 +60,12 @@ func init() { // // The full failure-mode matrix runs on Ubuntu2404 only: it is // systemd 255, where daemon-reload does not clear the start - // limiter and where the provisioning regression was found. It - // costs ~23min, so the other distros run the single - // discriminating mode instead (~40s) -- enough to catch the - // directives being dropped on those images. + // limiter and where the provisioning regression was found. On + // shortened clocks a healthy run of all seven modes costs ~7min, + // and the sizing against TestTimeoutVMSS is asserted at build + // time by TestLocalDNSFaultMatrixFitsVMSSBudget. The other + // distros run the single discriminating mode instead (~40s) -- + // enough to catch the directives being dropped on those images. faults := localdnsDiscriminatingFault() if tt.name == "Ubuntu2404" { faults = localdnsFaultMatrix @@ -76,9 +78,21 @@ func init() { } func validateLocalDNSLifecycle(ctx context.Context, s *Scenario) error { + // Gate the ExecStopPost block on the lane, not on the unit under test. Probing + // 'systemctl show -p ExecStopPost' to decide whether to test ExecStopPost means the + // assertion only ever runs where it is already guaranteed to pass, and removing the hook + // would turn the block off everywhere instead of failing it. laneResolvedMainBuiltImage + // (scenario_localdns_restart_budget.go) reads the lane's own image selection instead. + expectExecStopPost := "true" + if laneResolvedMainBuiltImage() { + expectExecStopPost = "false" + } _, err := execScriptOnVMForScenarioValidateExitCode(ctx, s, ` set -eu +# Set from the lane's image selection, not probed from the node. +EXPECT_EXECSTOPPOST=`+expectExecStopPost+` + NORESTART=/run/systemd/system/localdns.service.d/99-e2e-no-restart.conf # Install cleanup before any service mutation so set -e cannot leave the node @@ -214,7 +228,14 @@ if sudo journalctl -u localdns.service --since "@$test_start" --no-pager | grep fi dig +short +time=5 +tries=1 mcr.microsoft.com @169.254.10.10 | grep -q . -if sudo systemctl show localdns.service -p ExecStopPost --value | grep -q 'localdns.sh cleanup'; then +if [ "$EXPECT_EXECSTOPPOST" = true ]; then +# The lane asked for this branch's VHD, so the hook must be there. Assert it rather than +# using its presence to decide whether to look -- a missing hook is the regression. +if ! sudo systemctl show localdns.service -p ExecStopPost --value | grep -q 'localdns.sh cleanup'; then + echo "FAIL: ExecStopPost=localdns.sh cleanup is missing from localdns.service" + sudo systemctl show localdns.service -p ExecStopPost || true + exit 1 +fi # Terminal dead-service case: this is the incident scenario the PR fixes. # When localdns ends up dead (systemd exhausts restart attempts), ExecStopPost # must still revert node DNS so the node does not keep pointing at the dead @@ -308,7 +329,7 @@ if ! getent hosts mcr.microsoft.com >/dev/null 2>&1; then exit 1 fi else - echo "SKIP: VHD predates the ExecStopPost cleanup hook" + echo "SKIP: this lane resolved a main-built image, which predates the ExecStopPost cleanup hook" fi # The EXIT trap removes the temporary override and restores LocalDNS even if diff --git a/e2e/scenario/scenario_localdns_restart_budget.go b/e2e/scenario/scenario_localdns_restart_budget.go index 33621fd417e..e05a037ca86 100644 --- a/e2e/scenario/scenario_localdns_restart_budget.go +++ b/e2e/scenario/scenario_localdns_restart_budget.go @@ -3,9 +3,9 @@ package scenario import ( "context" "fmt" - "strings" "time" + "github.com/Azure/agentbaker/e2e/config" "github.com/Azure/agentbaker/e2e/logging" ) @@ -42,6 +42,11 @@ type localdnsFault struct { label string // seconds to wait for the unit to reach 'failed', from the measured time plus margin deadlineSeconds int + // what this mode actually took when last measured on the gate, in seconds. Data rather + // than a comment so TestLocalDNSFaultMatrixFitsVMSSBudget can size the matrix against + // TestTimeoutVMSS: the healthy run costs the sum of these, and only a regressing mode + // costs its deadline. + measuredSeconds int } // localdnsFaultMatrix is the full set of modes. @@ -63,13 +68,13 @@ type localdnsFault struct { // watchdog 370s WatchdogSec 60 -> 10 // hungstart 625s TimeoutStartSec 90 -> 15, TimeoutStopSec 30 -> 5 var localdnsFaultMatrix = []localdnsFault{ - {name: "preflight", label: "pre-flight abort", deadlineSeconds: 45}, // ~11s - {name: "resolvdrain", label: "resolv.conf never drains", deadlineSeconds: 80}, // ~37s - {name: "postready", label: "dies right after READY", deadlineSeconds: 120}, // ~64s - {name: "nopidfile", label: "PID file never appears", deadlineSeconds: 90}, // ~30s shortened - {name: "readytimeout", label: "ready-check timeout", deadlineSeconds: 120}, // ~75s shortened - {name: "watchdog", label: "watchdog pings cease", deadlineSeconds: 120}, // ~90s shortened - {name: "hungstart", label: "hung start", deadlineSeconds: 180}, // ~110s shortened + {name: "preflight", label: "pre-flight abort", deadlineSeconds: 45, measuredSeconds: 11}, + {name: "resolvdrain", label: "resolv.conf never drains", deadlineSeconds: 80, measuredSeconds: 37}, + {name: "postready", label: "dies right after READY", deadlineSeconds: 120, measuredSeconds: 64}, + {name: "nopidfile", label: "PID file never appears", deadlineSeconds: 90, measuredSeconds: 30}, + {name: "readytimeout", label: "ready-check timeout", deadlineSeconds: 120, measuredSeconds: 75}, + {name: "watchdog", label: "watchdog pings cease", deadlineSeconds: 120, measuredSeconds: 90}, + {name: "hungstart", label: "hung start", deadlineSeconds: 180, measuredSeconds: 110}, } // localdnsDiscriminatingFault is the single mode used on distros that do not carry the @@ -102,11 +107,37 @@ const ( // Kept separate from localdnsFaultDropIn so the real-clock measurement can run with the // shipped timeouts before the matrix speeds them up. localdnsFastClockDropIn = "/run/systemd/system/localdns.service.d/99-e2e-fastclock.conf" - // StartLimitIntervalSec=720 as systemd formats it. Shared by the provenance probe and - // the directive assertion so the two cannot drift apart. - localdnsExpectedStartLimitInterval = "12min" ) +// localdnsWorstCycleCeilingSeconds bounds measureLocalDNSWorstCycle's poll. Exported as a +// constant so TestLocalDNSFaultMatrixFitsVMSSBudget can size the whole validation against +// TestTimeoutVMSS at build time. +const localdnsWorstCycleCeilingSeconds = 180 + +// laneResolvedMainBuiltImage reports whether this lane asked for an image built from main, +// rather than one built from the branch under test. +// +// This is the gate for the restart-budget validation, and it deliberately reads the lane's +// own image selection rather than probing the node for the directives. Probing the node +// would key the skip on a value the validation itself asserts, so the assertion could only +// run on images where it was already guaranteed to pass -- and a later retune of the budget +// would silently turn the whole scenario off on every lane instead of failing it. +// +// The gate lane sets SIG_VERSION_TAG_NAME=buildId / SIG_VERSION_TAG_VALUE= +// from VHD_BUILD_ID (.pipelines/scripts/e2e_run.sh:83-88) and therefore tests this PR's own +// VHDs. Everything else falls back to the default branch=refs/heads/main selector, which +// resolves a main-built image that legitimately still ships the systemd default 10s/5 +// budget: localdns.service is baked into the VHD (vhdbuilder/packer/packer_source.sh), not +// delivered through CustomData. .pipelines/e2e.yaml triggers on any PR touching e2e/** and +// runs in exactly that configuration. +// +// A lane pointed at some other branch's image asserts rather than skips: if you asked for a +// specific branch's VHD, a missing budget there is a real failure worth hearing about. +func laneResolvedMainBuiltImage() bool { + return config.Config.SIGVersionTagName == "branch" && + config.Config.SIGVersionTagValue == "refs/heads/main" +} + // validateLocalDNSRestartBudget asserts that the unit's restart budget terminates each // supplied failure mode in 'failed', and leaves LocalDNS healthy afterwards. func validateLocalDNSRestartBudget(ctx context.Context, s *Scenario, faults []localdnsFault) error { @@ -114,11 +145,10 @@ func validateLocalDNSRestartBudget(ctx context.Context, s *Scenario, faults []lo return fmt.Errorf("no LocalDNS faults selected: the fault matrix is misconfigured") } - carries, err := vhdCarriesLocalDNSRestartBudget(ctx, s) - if err != nil { - return err - } - if !carries { + if laneResolvedMainBuiltImage() { + logging.Logf(ctx, "SKIP: this lane resolved a main-built image (%s=%s), which predates the "+ + "LocalDNS restart budget baked into the VHD; run against the PR's VHD build to exercise it", + config.Config.SIGVersionTagName, config.Config.SIGVersionTagValue) return nil } @@ -208,7 +238,7 @@ func measureLocalDNSWorstCycle(ctx context.Context, s *Scenario) error { return err } -const localdnsWorstCycleScript = ` +var localdnsWorstCycleScript = ` set -eu usec() { systemd-analyze timespan "$1" 2>/dev/null | sed -n '2s/.*: *//p'; } @@ -226,9 +256,13 @@ sudo rm -f ` + localdnsFaultCounter + ` sudo systemctl start --no-block localdns.service || true # Two ExecStarts is all that is needed. Worst case here is TimeoutStartSec 90 + -# TimeoutStopSec 30 + RestartSec 2 = ~122s, so 240s leaves generous headroom. +# TimeoutStopSec 30 + RestartSec 2 = ~122s. The ceiling is deliberately close to that +# rather than generous: this poll shares TestTimeoutVMSS with VM creation and the whole +# fault matrix, and if the scenario runs out of budget the VMSS timeout pre-empts the +# per-fault deadlines and you lose the specific diagnostic they exist to produce. On the +# success path it breaks early anyway. Keep it in step with localdnsWorstCycleCeilingSeconds. observed=0 -for i in $(seq 1 240); do +for i in $(seq 1 ` + fmt.Sprint(localdnsWorstCycleCeilingSeconds) + `); do observed=$(sudo grep -c EXECSTART ` + localdnsFaultCounter + ` 2>/dev/null || echo 0) [ "$observed" -ge 2 ] && break sleep 1 @@ -269,42 +303,6 @@ sudo systemctl is-active --quiet localdns.service || { } ` -// vhdCarriesLocalDNSRestartBudget reports whether the image under test actually ships the -// restart budget, so an image that predates it is skipped rather than failed. -// -// localdns.service is baked into the VHD (vhdbuilder/packer/packer_source.sh), not delivered -// through CustomData, so these directives only exist on an image built from a branch that -// carries them. Two e2e lanes run against this repo and they do not agree on which image -// that is: the VHD check-in gate builds this PR's own images and tests them, but -// .pipelines/e2e.yaml also triggers on any PR touching e2e/**, and it resolves images by -// branch=refs/heads/main -- which legitimately still ship the systemd default 10s/5 budget. -// Asserting unconditionally makes that second lane permanently red for any PR that changes -// this file, and the failure says "the directives were removed" about an image that was -// never meant to have them. -// -// StartLimitIntervalUSec is the probe rather than any other directive because it is -// unambiguous provenance: 12min exists only on an image carrying this change, and the 10s -// default identifies an older one. TimeoutStartUSec cannot be used -- it now reads 1min 30s -// on new images but also on any older Ubuntu image, so it does not separate them. -// -// This mirrors validateLocalDNSLifecycle, which already skips its terminal dead-service -// block on images predating the ExecStopPost cleanup hook. -func vhdCarriesLocalDNSRestartBudget(ctx context.Context, s *Scenario) (bool, error) { - result, err := execScriptOnVMForScenario(ctx, s, - `systemctl show localdns.service -p StartLimitIntervalUSec --value`) - if err != nil { - return false, fmt.Errorf("read the LocalDNS start-limit interval: %w", err) - } - interval := strings.TrimSpace(result.stdout) - if interval != localdnsExpectedStartLimitInterval { - logging.Logf(ctx, "SKIP: VHD predates the LocalDNS restart budget (StartLimitIntervalUSec=%q, want %q); "+ - "this image is not built from a branch carrying localdns.service's budget", - interval, localdnsExpectedStartLimitInterval) - return false, nil - } - return true, nil -} - // assertLocalDNSBudgetDirectives checks the effective directives rather than the file, so // a drop-in that quietly overrides them is caught too. func assertLocalDNSBudgetDirectives(ctx context.Context, s *Scenario) error { @@ -326,7 +324,7 @@ check() { } # The budget under test. -check StartLimitIntervalUSec "` + localdnsExpectedStartLimitInterval + `" +check StartLimitIntervalUSec "12min" check StartLimitBurst "5" check RestartUSec "2s" @@ -344,6 +342,15 @@ check Restart "on-failure" # margin, and this assertion, distro-dependent. Assert the pin so dropping it fails here. check TimeoutStartUSec "1min 30s" +# The other half of the same problem, and the one that actually bit. Azure Linux ships a +# global service.d drop-in setting TimeoutStopFailureMode=abort, which makes a stop timeout +# send SIGABRT and then wait a SECOND TimeoutStopSec before SIGKILL. The stop side of the +# cycle is doubled, and the arithmetic below -- which models it as one TimeoutStopSec -- has +# no way to see that. Measured on AzureLinuxV3: 153s against a 144s threshold. The unit pins +# 'terminate' to take the distro's drop-in out of the cycle; assert the pin, because if it is +# dropped the margin check below still reports a comfortable 122s while the machine is at 153s. +check TimeoutStopFailureMode "terminate" + # The design rule itself, as arithmetic on the live values rather than on the numbers this # comment happens to quote. # @@ -386,13 +393,16 @@ if [ "$fail" -ne 0 ]; then echo "delivered through CustomData, so these directives only exist on an image built" echo "from a branch that carries them." echo - echo "Reaching this message means the image DOES carry the budget -- vhdCarriesLocalDNSRestartBudget" - echo "already matched StartLimitIntervalUSec and would have skipped an older image before" - echo "getting here. So one of the other directives was removed, overridden by a drop-in," - echo "or is inherited on this distro when it should be pinned." + echo "This validation is gated on the lane, not on the node: laneResolvedMainBuiltImage()" + echo "skips it when the lane asked for a main-built image. Reaching this message therefore" + echo "means the lane asked for THIS branch's VHD and the image it got does not have the" + echo "budget -- either it was removed, a drop-in overrode it, or it is inherited on this" + echo "distro when the unit should be pinning it." echo - echo "Note TimeoutStartUSec is pinned by the unit precisely because the manager default is" - echo "a systemd build-time constant: Ubuntu builds it at 90s, Azure Linux at 45s." + echo "TimeoutStartUSec and TimeoutStopFailureMode are both pinned by the unit precisely" + echo "because their defaults are systemd build-time constants that differ by image:" + echo "Ubuntu builds the start timeout at 90s and Azure Linux at 45s, and Azure Linux also" + echo "ships a global TimeoutStopFailureMode=abort drop-in that doubles the stop side." fi exit "$fail" diff --git a/e2e/scenario/scenario_localdns_restart_budget_test.go b/e2e/scenario/scenario_localdns_restart_budget_test.go new file mode 100644 index 00000000000..ed110eab9a3 --- /dev/null +++ b/e2e/scenario/scenario_localdns_restart_budget_test.go @@ -0,0 +1,94 @@ +package scenario + +import ( + "testing" + "time" + + "github.com/Azure/agentbaker/e2e/config" +) + +// localdnsNonMatrixAllowance is the time the LocalDNS scenarios must leave for everything +// that is not the fault matrix: VMSS create, node bootstrap, the scenario's default +// provisioning validation, validateLocalDNSLifecycle, and the provisioning-restart loop. +// +// Measured on the check-in gate (build 181710671, LocalDNSHostsPlugin/Ubuntu2404): VM +// creation and the default validations finished at 181s, and the lifecycle validation plus +// the provisioning-restart loop added roughly another 100s. 300s is that with margin, +// because creation time is the part we do not control. +const localdnsNonMatrixAllowance = 300 * time.Second + +// TestLocalDNSFaultMatrixFitsVMSSBudget fails the build when the fault matrix can no longer +// finish inside TestTimeoutVMSS. +// +// This exists because going over the budget does not fail like a sizing error. The VMSS +// context deadline pre-empts the per-fault deadline, so instead of the specific diagnostic +// the matrix is built to produce -- "hung start did not terminate in 'failed' within 180s", +// which says the restart budget stopped bounding that mode -- you get a generic scenario +// timeout that says nothing. Every per-fault deadline is carefully sized, and all of that +// work is wasted the moment the sum stops fitting. +// +// The model is "a healthy run plus one regression", not "every deadline fires at once": +// +// allowance + worst-cycle ceiling + sum(measured) + max(deadline - measured) +// +// A mode only costs its deadline when it is broken, and the first broken mode aborts the +// run, so at most one overrun is ever paid. Summing all seven deadlines would instead +// assert a state that can never be reached and would force the matrix to be cut for no +// reason. What this does guarantee is the property that matters: if any single mode +// regresses, its deadline fires and reports itself before the VMSS context expires. +func TestLocalDNSFaultMatrixFitsVMSSBudget(t *testing.T) { + vmssBudget := config.DefaultConfiguration().TestTimeoutVMSS + + var healthy time.Duration + var worstOverrun time.Duration + for _, fault := range localdnsFaultMatrix { + if fault.measuredSeconds <= 0 { + t.Errorf("fault %q has no measuredSeconds; the matrix cannot be sized against "+ + "TestTimeoutVMSS without it. Run the mode on the gate and record what it took.", + fault.name) + continue + } + if fault.deadlineSeconds <= fault.measuredSeconds { + t.Errorf("fault %q has deadlineSeconds=%d at or below measuredSeconds=%d; it will "+ + "fail on a healthy node", fault.name, fault.deadlineSeconds, fault.measuredSeconds) + continue + } + healthy += time.Duration(fault.measuredSeconds) * time.Second + if overrun := time.Duration(fault.deadlineSeconds-fault.measuredSeconds) * time.Second; overrun > worstOverrun { + worstOverrun = overrun + } + } + + // The worst-cycle measurement runs before the matrix and can spend its full poll. + ceiling := localdnsWorstCycleCeilingSeconds * time.Second + total := localdnsNonMatrixAllowance + ceiling + healthy + worstOverrun + + if total > vmssBudget { + t.Errorf( + "LocalDNS restart-budget validation cannot fit TestTimeoutVMSS.\n"+ + " non-matrix allowance: %v (VM create + default validation + lifecycle)\n"+ + " worst-cycle ceiling: %v\n"+ + " healthy matrix run: %v (%d modes)\n"+ + " worst single overrun: %v\n"+ + " total: %v\n"+ + " TestTimeoutVMSS: %v\n"+ + "Over by %v. Reduce a deadline, drop a fault from localdnsFaultMatrix, lower "+ + "localdnsWorstCycleCeilingSeconds, or move the matrix to its own scenario. Do not "+ + "raise the allowance without a measurement to back it.", + localdnsNonMatrixAllowance, ceiling, healthy, len(localdnsFaultMatrix), + worstOverrun, total, vmssBudget, total-vmssBudget, + ) + } +} + +// TestLocalDNSDiscriminatingFaultIsInMatrix guards localdnsDiscriminatingFault's lookup. +// +// It returns nil if the matrix no longer contains the mode it names, and a nil fault list +// makes validateLocalDNSRestartBudget fail every non-Ubuntu2404 lane with a confusing +// "fault matrix is misconfigured" at runtime. Catch a rename here instead. +func TestLocalDNSDiscriminatingFaultIsInMatrix(t *testing.T) { + if got := localdnsDiscriminatingFault(); len(got) != 1 { + t.Fatalf("localdnsDiscriminatingFault() returned %d faults, want exactly 1; "+ + "the mode it looks up is no longer in localdnsFaultMatrix", len(got)) + } +} From f31bb561c76793807257df41ee4f9ca5bfee2df0 Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Fri, 18 Sep 2026 22:54:49 +0000 Subject: [PATCH 21/26] fix: restore the provisioning diagnostics the inlined retry loop dropped Replacing systemctlEnableAndStart with an inline loop (to clear the StartLimit budget between attempts) silently took four diagnostics with it. Only one of the five the helper produced survived. What the helper did, via systemctl_restart -> _systemctl_retry_svc_operation with shouldLogRetryInfo=true: - 'systemctl status' + 'journalctl -u localdns' on every failed attempt - echo + status log to /var/log/azure/localdns-status.log when the start failed - echo + status log to the same file when 'systemctl enable' failed The inline loop kept only the status log on the start-failure path. An enable failure exited with nothing but the code, and the 100 retries produced no record of what was going wrong. Restored, but deliberately not as it was: - Diagnostics during retries are sampled (every tenth attempt) and the journal is bounded with -n 50. The helper dumped status plus an UNBOUNDED 'journalctl -u' on all 99 failed attempts, measured at 6-8s per iteration, which consumed a large part of the provisioning window it was retrying inside. Sampling keeps the record without paying that. - Both failure paths now echo which step failed and append a bounded journal to the status log. The status snapshot alone is taken ~5s after the last failed restart, when the unit is normally 'activating (auto-restart)' rather than 'failed' -- the loop cleared the start-limit counter on every iteration, so it cannot have accumulated toward the terminal state. That snapshot describes a unit mid-cycle and explains none of the failures, so the journal has to accompany it. - Give-up reports distinguish exhausting the 100 attempts from running out of CSE budget. Those mean different things: localdns is broken, versus provisioning ran out of time and never finished trying. ShellSpec covers all four paths, and each was mutation-checked -- reverting either the enable-path logging or the periodic sampling fails its test. Co-Authored-By: Claude Opus 5 (1M context) --- .../artifacts/cse_config_localdns.sh | 35 ++++++++++- .../artifacts/cse_config_localdns_spec.sh | 62 +++++++++++++++++++ 2 files changed, 95 insertions(+), 2 deletions(-) diff --git a/parts/linux/cloud-init/artifacts/cse_config_localdns.sh b/parts/linux/cloud-init/artifacts/cse_config_localdns.sh index 45ebf0ffb0e..d6aee52884a 100644 --- a/parts/linux/cloud-init/artifacts/cse_config_localdns.sh +++ b/parts/linux/cloud-init/artifacts/cse_config_localdns.sh @@ -127,23 +127,54 @@ enableLocalDNS() { # These all talk to PID 1 over D-Bus; an unbounded one that wedges would never return to # the top of the loop, so check_cse_timeout above would never be re-evaluated and CSE # would be SIGKILLed before it could report. + local localdns_giveup_reason="exhausted 100 restart attempts" for i in $(seq 1 100); do - check_cse_timeout || break + if ! check_cse_timeout; then + localdns_giveup_reason="CSE provisioning budget exhausted at attempt ${i}" + break + fi timeout 30 systemctl reset-failed localdns 2>/dev/null || true timeout 30 systemctl daemon-reload if timeout 30 systemctl restart localdns; then localdns_started=true break fi + # Periodic, bounded diagnostics. systemctlEnableAndStart used to dump 'systemctl status' + # plus an unbounded 'journalctl -u' on every failed attempt (shouldLogRetryInfo=true in + # _systemctl_retry_svc_operation), which is ~99 dumps and a measured 6-8s per iteration -- + # enough to eat most of the provisioning window on its own. Dropping it entirely lost the + # only record of what was going wrong across the retries, so sample it instead: every + # tenth attempt, with the journal bounded by -n. + if [ $((i % 10)) -eq 0 ]; then + echo "localdns restart attempt ${i}/100 failed; unit state and recent journal follow." + timeout 30 systemctl status localdns --no-pager -l || true + timeout 30 journalctl -u localdns --no-pager -n 50 || true + fi sleep 5 done if [ "${localdns_started}" != "true" ]; then + echo "localdns could not be started: ${localdns_giveup_reason}." # No reset here -- the last failure's auto-restarts land the unit in 'failed', which is the # terminal state NPD needs. + # + # This snapshot is taken ~5s after the last failed restart, so the unit is normally + # 'activating (auto-restart)' rather than 'failed': the loop cleared the start-limit + # counter on every iteration, so it cannot have accumulated toward the terminal state yet. + # That is why the journal is captured alongside it -- the status line alone describes a + # unit mid-cycle and does not explain why any of the attempts failed. + timeout 30 systemctl status localdns --no-pager -l > /var/log/azure/localdns-status.log || true + timeout 30 journalctl -u localdns --no-pager -n 200 >> /var/log/azure/localdns-status.log || true + exit $ERR_LOCALDNS_FAIL + fi + # Log on this path too. systemctlEnableAndStart wrote a status log when 'systemctl enable' + # failed as well as when the start failed; inlining the loop kept the start path and dropped + # this one, so an enable failure exited with nothing but the code. + if ! retrycmd_if_failure 120 5 25 systemctl enable localdns; then + echo "localdns could not be enabled by systemctl." timeout 30 systemctl status localdns --no-pager -l > /var/log/azure/localdns-status.log || true + timeout 30 journalctl -u localdns --no-pager -n 200 >> /var/log/azure/localdns-status.log || true exit $ERR_LOCALDNS_FAIL fi - retrycmd_if_failure 120 5 25 systemctl enable localdns || exit $ERR_LOCALDNS_FAIL echo "Enable localdns succeeded." # Exporter socket setup is deferred to configureLocalDNSExporterSocket() (after ensureKubelet) # to avoid delaying kubelet start. The kubelet node label is added separately in cse_main.sh. diff --git a/spec/parts/linux/cloud-init/artifacts/cse_config_localdns_spec.sh b/spec/parts/linux/cloud-init/artifacts/cse_config_localdns_spec.sh index cba34720f88..6154a31bccc 100755 --- a/spec/parts/linux/cloud-init/artifacts/cse_config_localdns_spec.sh +++ b/spec/parts/linux/cloud-init/artifacts/cse_config_localdns_spec.sh @@ -57,6 +57,17 @@ Describe 'cse_config_localdns.sh' echo "retrycmd_if_failure $*" return 0 } + # enableLocalDNS captures the journal alongside 'systemctl status' on the failure + # paths. Mock it so the assertions are deterministic and no real journal is read. + journalctl() { + echo "journalctl $*" + return 0 + } + # The give-up and enable-failure paths redirect into this directory. Without it the + # redirect fails before the command runs and the '|| true' hides it, so the tests + # would pass without ever exercising the capture. + mkdir -p /var/log/azure + rm -f /var/log/azure/localdns-status.log sleep() { : } @@ -152,6 +163,57 @@ Describe 'cse_config_localdns.sh' # for NPD: the trace must end on a start attempt, never on a reset. The contents of file "$TMP_DIR/trace" should end with "S" End + + It 'should say why it gave up and capture the journal, not just the unit state' + # systemctlEnableAndStart logged 'systemctl status' plus 'journalctl -u' on every + # failed attempt; inlining the loop dropped all of it. The snapshot alone shows a + # unit mid-restart-cycle and does not explain any of the failures, so the journal + # has to come with it. + restart_failures_before_success=99999 + tracing_systemctl + When run enableLocalDNS + The status should equal 216 + The output should include "localdns could not be started: exhausted 100 restart attempts." + The contents of file /var/log/azure/localdns-status.log should include "journalctl -u localdns" + End + + It 'should report a CSE budget give-up differently from exhausting the attempts' + # The two give-up reasons need different messages: one means localdns is broken, + # the other means provisioning ran out of time and never finished trying. + restart_failures_before_success=99999 + tracing_systemctl + check_cse_timeout() { return 1; } + When run enableLocalDNS + The status should equal 216 + The output should include "CSE provisioning budget exhausted at attempt 1" + The output should not include "exhausted 100 restart attempts" + End + + It 'should sample diagnostics during the retries without dumping on every attempt' + # Bounded and periodic on purpose: the old helper dumped status plus an unbounded + # journal on all 99 failed attempts, measured at 6-8s per iteration, which ate the + # provisioning window it was retrying inside. + restart_failures_before_success=11 + tracing_systemctl + When run enableLocalDNS + The status should be success + The output should include "localdns restart attempt 10/100 failed" + The output should include "journalctl -u localdns --no-pager -n 50" + The output should not include "localdns restart attempt 9/100 failed" + The output should include "Enable localdns succeeded." + End + + It 'should log and capture status when systemctl enable fails' + # systemctlEnableAndStart wrote a status log on the enable-failure path as well as + # the start-failure path. Inlining the loop kept the first and dropped the second, + # so an enable failure exited with nothing but the code. + retrycmd_if_failure() { return 1; } + When run enableLocalDNS + The status should equal 216 + The output should include "localdns could not be enabled by systemctl." + The output should not include "Enable localdns succeeded." + The contents of file /var/log/azure/localdns-status.log should include "journalctl -u localdns" + End End Describe 'enableLocalDNSForScriptless' setup() { From 90c3922c6bb93ba76542ce1beafffd6d0602acea Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Mon, 21 Sep 2026 17:47:13 +0000 Subject: [PATCH 22/26] docs: record what trapping SIGTERM did to a localdns stop, and pin it with a spec The TERM trap added to reap the watchdog sleep also made 'exit 0' fire the EXIT trap, so cleanup_localdns_configs now runs in-process on every systemd stop where previously bash died first and only ExecStopPost ran. That was a side effect, not a decision, and nothing recorded it. Keeping the behaviour. Measured on a node rather than argued (journal from gate build 181777373, AzureLinuxV3, n=11 stops / n=18 starts): stop 5-6s (essentially all of it LOCALDNS_SHUTDOWN_DELAY draining) start 1-2s restart 6-8s against the 'timeout 30 systemctl restart localdns' in enableLocalDNS() and its e2e mirror -- ~22-24s of headroom So the cost lands at about a quarter of the only bound that constrains it, and the behaviour it buys is better than the alternative: without the drain CoreDNS is SIGKILLed by the cgroup on every stop, dropping in-flight queries. Trimming it would spend real shutdown quality to reclaim time nothing needs. It does not move the restart-budget math. The worst cycle is a hung start, where this trap cannot run at all -- bash defers a trapped signal until the foreground command returns, and that fault never returns -- so systemd spends the full TimeoutStopSec there regardless. Second consequence, previously unrecorded: cleanup_localdns_configs now runs to completion, so the dummy interface carrying .10/.11 is torn down on a stop. localdns_cleanup_mode (ExecStopPost) deliberately leaves the link alone in case an orphaned CoreDNS is still answering on .11, so the two paths used to differ; for a clean stop they now agree. The teardown/recreate cycle was clean in the same run: 12 teardowns, 18 setups, zero address-in-use or RTNETLINK errors. Worth knowing for #9486 -- its "create the dummy interface idempotently" constraint is now the common case on a clean stop rather than the exception. The spec covers the trap wiring, which nothing did before. The traps sit below "${__SOURCED__:+return}", so Include cannot reach them; the spec greps the real trap lines out of the shipped script and executes them against stubs instead of restating them, so deleting or altering a trap fails the test. Mutation-checked both ways: removing the TERM trap fails all three examples, and changing its 'exit 0' to 'exit 1' fails all three. Comment and test only; no behaviour change. Co-Authored-By: Claude Opus 5 (1M context) --- parts/linux/cloud-init/artifacts/localdns.sh | 31 ++++++++ .../cloud-init/artifacts/localdns_spec.sh | 71 +++++++++++++++++++ 2 files changed, 102 insertions(+) diff --git a/parts/linux/cloud-init/artifacts/localdns.sh b/parts/linux/cloud-init/artifacts/localdns.sh index 365a610b08b..51e2924b240 100644 --- a/parts/linux/cloud-init/artifacts/localdns.sh +++ b/parts/linux/cloud-init/artifacts/localdns.sh @@ -41,6 +41,9 @@ LOCALDNS_NODE_LISTENER_IP="169.254.10.10" LOCALDNS_CLUSTER_LISTENER_IP="169.254.10.11" # Localdns shutdown delay. +# Paid on every exit that finds CoreDNS still running, which since the SIGTERM trap +# (see the trap block near the end of this file) includes every systemd stop, not just +# the script's own error exits. Measured contribution to a stop: 5-6s of a 6-8s restart. LOCALDNS_SHUTDOWN_DELAY=5 # Localdns pid file. @@ -1108,6 +1111,34 @@ trap 'echo "Error occurred. Cleaning up..."; cleanup_localdns_configs; exit $ERR # default action: the EXIT cleanup below never ran, and any in-flight watchdog sleep was # left orphaned in the cgroup. Handle it so the child is reaped and cleanup runs. Exit 0 # because a requested stop is not a failure -- Restart=on-failure must not fire for it. +# +# Trapping SIGTERM changes what a systemd stop does, and the change is deliberate. 'exit 0' +# fires the EXIT trap below, so cleanup_localdns_configs now runs IN-PROCESS on every stop, +# where previously bash died first and only ExecStopPost ran. Two consequences, both +# measured on a node rather than reasoned about (journal from gate build 181777373, +# AzureLinuxV3, n=11 stops): +# +# 1. A stop takes 5-6s instead of being immediate. Essentially all of it is +# LOCALDNS_SHUTDOWN_DELAY (:44) draining connections before CoreDNS is SIGINTed. +# Measured stop 5-6s, start 1-2s, so a full restart is 6-8s. The tightest bound on +# that path is 'timeout 30 systemctl restart localdns' in enableLocalDNS() +# (cse_config_localdns.sh) and its e2e mirror, leaving ~22-24s of headroom. It does +# not affect the restart-budget cycle math either: the worst cycle is a hung start, +# where this trap cannot run at all because bash defers a trapped signal until the +# foreground command returns, so systemd spends the full TimeoutStopSec regardless. +# +# 2. cleanup_localdns_configs runs to completion, so the dummy interface carrying +# 169.254.10.10/.11 is now torn down on a stop. It was not before: localdns_cleanup_mode +# (the ExecStopPost path) deliberately leaves the link alone in case an orphaned CoreDNS +# is still answering on .11. Both paths are now consistent for a clean stop, and the +# teardown/recreate cycle was clean in the same run (12 teardowns, 18 setups, zero +# address-in-use or RTNETLINK errors). Note this for the pod-DNS fallback (#9486): its +# idempotent-interface-creation requirement is now the common case on a clean stop, not +# the exception. +# +# The graceful path is kept rather than trimmed because the cost is affordable at the only +# bound that matters and the behaviour is better than the alternative -- without it CoreDNS +# is SIGKILLed by the cgroup on every stop, dropping in-flight queries. trap 'echo "Received SIGTERM, shutting down."; stop_watchdog_sleep; exit 0' TERM trap 'echo "Executing cleanup function."; cleanup_localdns_configs || echo "Cleanup failed with error code: $ERR_LOCALDNS_FAIL."' EXIT diff --git a/spec/parts/linux/cloud-init/artifacts/localdns_spec.sh b/spec/parts/linux/cloud-init/artifacts/localdns_spec.sh index 9b3bb321af6..912f51731a0 100644 --- a/spec/parts/linux/cloud-init/artifacts/localdns_spec.sh +++ b/spec/parts/linux/cloud-init/artifacts/localdns_spec.sh @@ -1328,6 +1328,77 @@ EOF End +# This section tests the signal traps installed at the bottom of localdns.sh. +#--------------------------------------------------------------------------------------------------- +# These cannot be reached with Include: they sit below "${__SOURCED__:+return}", which is what +# stops sourcing from running the main block. The trap wiring is nonetheless the thing that +# decides what a systemd stop does -- a stop sends SIGTERM, and whether that reaps the watchdog +# sleep, runs cleanup in-process, and exits 0 is entirely determined by those three lines. +# +# So extract the real trap lines out of the shipped script and execute them, rather than +# restating them here. A spec that restated them would pass even if the traps were deleted, +# which is the failure mode worth avoiding: it would report healthy while a stop reverted to +# bash dying on the default action, leaving the watchdog sleep orphaned in the cgroup and +# cleanup to ExecStopPost alone. + Describe 'signal traps' + LOCALDNS_SRC="./parts/linux/cloud-init/artifacts/localdns.sh" + + # Build a harness containing the real trap lines plus stubs for what they call, so the + # assertions below are about the shipped text and not about a copy of it. + build_trap_harness() { + harness=$(mktemp) + { + echo '#!/bin/bash' + echo 'cleanup_localdns_configs() { echo "CLEANUP_RAN"; return 0; }' + echo 'stop_watchdog_sleep() { echo "WATCHDOG_REAPED"; }' + echo 'ERR_LOCALDNS_FAIL=99' + grep -E "^trap .*TERM$" "$LOCALDNS_SRC" + grep -E "^trap .*EXIT$" "$LOCALDNS_SRC" + echo 'kill -TERM $$' + # Long enough that the process is unambiguously still here if the signal is + # ignored, so a missing trap shows up as a timeout rather than a pass. + echo 'sleep 10' + echo 'echo "REACHED_AFTER_SIGNAL"' + } > "$harness" + } + cleanup_harness() { + rm -f "$harness" + } + BeforeEach 'build_trap_harness' + AfterEach 'cleanup_harness' + + It 'reaps the watchdog sleep and runs cleanup in-process on SIGTERM' + # This is what changed a systemd stop: before SIGTERM was trapped, bash died on the + # default action and neither of these ran. Both now do, which is what makes a stop + # cost the LOCALDNS_SHUTDOWN_DELAY drain and tear the dummy interface down. + When run command bash "$harness" + The output should include "Received SIGTERM, shutting down." + The output should include "WATCHDOG_REAPED" + The output should include "Executing cleanup function." + The output should include "CLEANUP_RAN" + The status should be success + End + + It 'exits 0 on SIGTERM so Restart=on-failure does not fire for a requested stop' + # A non-zero exit here would make systemd treat every 'systemctl stop' as a failure + # and restart the unit, and would also spend a slot of the StartLimitBurst budget. + When run command bash "$harness" + The status should equal 0 + The output should not include "REACHED_AFTER_SIGNAL" + End + + It 'reports cleanup failure rather than exiting non-zero' + # The EXIT trap deliberately swallows a cleanup failure: a best-effort cleanup error + # must not turn a requested stop into a systemd failure. + sed -i 's/cleanup_localdns_configs() { echo "CLEANUP_RAN"; return 0; }/cleanup_localdns_configs() { echo "CLEANUP_RAN"; return 1; }/' "$harness" + When run command bash "$harness" + The output should include "CLEANUP_RAN" + The output should include "Cleanup failed with error code: 99." + The status should equal 0 + End + End + + # This section tests - start_localdns_watchdog # These functions is also defined in parts/linux/cloud-init/artifacts/localdns.sh file. #------------------------------------------------------------------------------------------------------------------------------------ From e1f31d96955131636e68c49cabe9c3be10fe8cb8 Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Mon, 21 Sep 2026 18:03:15 +0000 Subject: [PATCH 23/26] test(e2e): keep the node scripts under the Bastion limit, and bound the burst check Two fixes, both from reviewing the e2e after build 181818040 lost three LocalDNS lanes. 1. The lifecycle script outgrew the Bastion tunnel. Scripts are SCP'd to the node, and tunnelSession.Write (bastionssh.go) forwards each SSH packet as one websocket message with no chunking against Bastion's 8,192-byte cap. go-scp sends a 4,096-byte first chunk then the remainder in a single write, so max_write = script_size - 4096 + 45 (45 = framing + MAC) which first exceeds the cap at a script size of 12,243. The lifecycle script had been sitting 380 bytes under that and grew 512, producing the 8,324-byte write that appears verbatim in the StatusMessageTooBig close frame. The scenario dies as a lost SSH session and loses its node logs, so nothing points at script length as the cause. 53% of that script was comments. Comments cost the same on the wire as code and do nothing at runtime, so the rationale moves into the Go doc comment -- none of it is lost, and the script goes 12,375 -> 6,821 bytes. The same treatment on localdnsFaultRunScript takes it 5,765 -> ~4,170, which matters more than it looks: that one is sent seven times per run. TestLocalDNSScriptsFitBastionLimit now measures every script this package sends, not just the one that broke, and prints the headroom. The real fix is chunking in tunnelSession.Write. That is shared e2e infrastructure and out of scope here; this guard holds the line until it lands, and every other caller in the suite still has the same cliff. 2. The ExecStart count is now bounded on both sides. The comment claimed "exactly the burst should have run" while the check only rejected fewer, so a limiter that allowed twenty starts before eventually tripping would pass -- the journal refusal line appears either way. It is now [burst, burst+1]. The upper bound has deliberate slack. Copilot twice recommended equality; the two measurements disagree on whether that is safe: by hand, live node (2026-09-17): postready = 6, others 5 CI, gate build 181777373 (Ubuntu2404): postready = 5, every mode 5 The 6 is unreproduced and unexplained. Tolerating it costs little -- a limiter allowing exactly one extra start slips through -- against a lane that flakes only when it recurs. The doc comment records both numbers so the next reader sees the conflict rather than re-tightening it, and notes that the hungstart journal count is not usable evidence here because measureLocalDNSWorstCycle runs that same fault before the matrix. Also recorded: $burst is read from the live unit, so this compares the SUT against itself, and is only sound because assertLocalDNSBudgetDirectives pins StartLimitBurst to 5 earlier in the same validation. Removing or reordering that assertion silently guts this check. Co-Authored-By: Claude Opus 5 (1M context) --- e2e/scenario/scenario_localdns_hosts.go | 205 ++++++++++-------- .../scenario_localdns_restart_budget.go | 40 +++- .../scenario_localdns_script_size_test.go | 76 +++++++ 3 files changed, 225 insertions(+), 96 deletions(-) create mode 100644 e2e/scenario/scenario_localdns_script_size_test.go diff --git a/e2e/scenario/scenario_localdns_hosts.go b/e2e/scenario/scenario_localdns_hosts.go index 07d4764d7ed..d21680bc62a 100644 --- a/e2e/scenario/scenario_localdns_hosts.go +++ b/e2e/scenario/scenario_localdns_hosts.go @@ -77,52 +77,126 @@ func init() { } } +// validateLocalDNSLifecycle exercises localdns.service end to end on the node: a normal +// stop/start, three supervisor kills recovered by Restart=on-failure, and the terminal +// dead-service case that #9360's ExecStopPost hook exists to handle. +// +// # Why the shell below is sparsely commented +// +// The script is SCP'd to the node, and the e2e's Bastion tunnel (bastionssh.go) forwards +// each SSH packet as a single websocket message with no chunking, against an 8,192-byte +// service cap. go-scp emits the body as a 4,096-byte chunk then the remainder, so +// max_write = script_size - 4096 + 45, and any script over 12,242 bytes kills the tunnel +// mid-run with StatusMessageTooBig. Build 181818040 lost three lanes to exactly that, after +// this script grew 512 bytes past a margin of 380. TestLocalDNSScriptsFitBastionLimit now +// guards every script this package sends. +// +// Comments cost the same as code on that wire and buy nothing at runtime, so the reasoning +// lives here instead. Keep the shell terse; put the "why" in this comment. +// +// # Lane gating (EXPECT_EXECSTOPPOST) +// +// Set from the lane's own image selection rather than probed from the node. Asking +// 'systemctl show -p ExecStopPost' whether to test ExecStopPost means the assertion only +// runs where it is already guaranteed to pass, and deleting the hook would silently turn +// the block off everywhere instead of failing it. See laneResolvedMainBuiltImage. +// +// # The EXIT trap +// +// Installed before any service mutation so 'set -e' cannot leave the node carrying the +// temporary Restart=no override or a failed unit. +// +// The override is removed unconditionally rather than behind '[ -f "$NORESTART" ]'. That +// test runs unprivileged, but sudo creates the drop-in inside a directory that root's umask +// makes 0750 root:root, so the guard could not stat the file, returned false, and skipped +// its own removal -- leaving Restart=no in effect for everything that ran afterwards on the +// node. 'rm -f' is already a no-op when the file is absent, so the guard bought nothing. +// The post-removal check uses 'sudo test -f' for the same reason. +// +// The restore retries rather than firing a single start. The kill block above can leave an +// orphaned CoreDNS holding 169.254.10.10:53 for a moment (the "Failed to kill control +// group" warning this test tolerates), and an immediate start then fails to bind. That is +// the exact transient RestartSec=2 exists to wait out in production, so wait for it here +// rather than failing the scenario on a cleanup race. +// +// # Kill/recovery cycles +// +// reset-failed runs before every kill. The budget (StartLimitBurst=5 within +// StartLimitIntervalSec=720) belongs to the unit and is shared by every actor that starts +// it -- CSE at provisioning, the validations above, and systemd's own Restart=on-failure. +// Without the reset, too few slots remain and the third kill's restart is refused with +// "Start request repeated too quickly", failing this loop for the wrong reason. What is +// under test here is Restart=on-failure, not the rate limiter. +// +// Recovery requires a genuinely new MainPID: immediately after kill -9 systemd may still +// report the killed invocation as active/running until it processes SIGCHLD, so checking +// active/running alone can observe the old process and falsely declare recovery. +// +// NRestarts is asserted >=1, not 3, because reset-failed zeroes it too -- it therefore +// reports the final cycle only. The three cycles are already proven individually by the +// new-MainPID requirement; this is a last check that the final kill was recovered by +// Restart=on-failure and not by something else. +// +// The StartLimit journal check is scoped with --since to these cycles: deliberately +// exhausting the budget is the expected outcome of validateLocalDNSRestartBudget, which +// runs after this returns. The cgroup teardown warning is surfaced but not failed on -- +// fixing it is out of scope for this PR. +// +// # Terminal dead-service case +// +// The dead state is reached with a transient Restart=no drop-in and one kill, rather than +// by tripping StartLimit with rapid kills, which is timing-dependent and flaky. +// ExecStopPost runs on the SIGKILL path regardless of Restart=. +// +// Termination is awaited on ActiveState, not SubState: SubState passes through transitional +// values such as stop-post while ExecStopPost is still running the cleanup under test, so +// asserting on drop-in removal then would race it. ActiveState only becomes failed/inactive +// after ExecStopPost completes. +// +// The drop-in absence check uses 'sudo ls' because it concludes "absent" from a failed +// glob. If that directory were ever created root-only -- as this test's own drop-in +// directory is -- an unprivileged ls would fail, the check would read that as success, and +// the regression under test would pass silently. It is 0755 today; the assertion should not +// depend on that. +// +// The resolver check polls because networkctl reload propagates to systemd-resolved +// asynchronously, and it rejects empty or unreadable snapshots rather than treating them as +// "restored" -- a failed read would otherwise mask the regression. Removing the address is +// not sufficient on its own, so a working resolver is verified with getent afterwards. func validateLocalDNSLifecycle(ctx context.Context, s *Scenario) error { - // Gate the ExecStopPost block on the lane, not on the unit under test. Probing - // 'systemctl show -p ExecStopPost' to decide whether to test ExecStopPost means the - // assertion only ever runs where it is already guaranteed to pass, and removing the hook - // would turn the block off everywhere instead of failing it. laneResolvedMainBuiltImage - // (scenario_localdns_restart_budget.go) reads the lane's own image selection instead. expectExecStopPost := "true" if laneResolvedMainBuiltImage() { expectExecStopPost = "false" } - _, err := execScriptOnVMForScenarioValidateExitCode(ctx, s, ` + _, err := execScriptOnVMForScenarioValidateExitCode(ctx, s, + localdnsLifecycleScript(expectExecStopPost), 0, "LocalDNS lifecycle validation failed") + return err +} + +// localdnsLifecycleScript renders the script validateLocalDNSLifecycle runs on the node. +// Split out from the caller so TestLocalDNSScriptsFitBastionLimit can measure the assembled +// result -- see that test and this file's doc comment for why the size matters. +func localdnsLifecycleScript(expectExecStopPost string) string { + return ` set -eu -# Set from the lane's image selection, not probed from the node. -EXPECT_EXECSTOPPOST=`+expectExecStopPost+` +EXPECT_EXECSTOPPOST=` + expectExecStopPost + ` NORESTART=/run/systemd/system/localdns.service.d/99-e2e-no-restart.conf -# Install cleanup before any service mutation so set -e cannot leave the node -# with the temporary Restart=no override or a failed LocalDNS unit. restore_localdns_test_state() { test_status=$? trap - EXIT set +e cleanup_status=0 - # Remove unconditionally rather than guarding on [ -f "$NORESTART" ]. That test runs - # unprivileged, but the drop-in is created by sudo into a directory that root's umask - # makes 0750 root:root -- so the test could not stat the file, returned false, and the - # removal was skipped. The Restart=no override then survived the test and stayed in - # effect for everything that ran afterwards on the node. 'rm -f' is a no-op when the - # file is absent, so there is nothing to guard. + # Unconditional: an unprivileged [ -f ] cannot stat inside the 0750 root-owned dir. sudo rm -f "$NORESTART" || { echo "ERROR: failed to remove $NORESTART"; cleanup_status=1; } sudo systemctl daemon-reload || { echo "ERROR: systemd daemon-reload failed during test cleanup"; cleanup_status=1; } if sudo test -f "$NORESTART"; then echo "ERROR: $NORESTART still present after cleanup" cleanup_status=1 fi - # The restart loop can hit systemd's start limit without creating NORESTART. - # Clear any failed state before trying to start LocalDNS; this is best-effort - # so a reset failure does not prevent the rest of cleanup. - # Retry the restore rather than firing a single start. The block above kills the - # supervisor, and the "Failed to kill control group" warning this test tolerates means - # an orphaned CoreDNS can still hold 169.254.10.10:53 for a moment afterwards -- an - # immediate start then fails to bind and exits with an error. That is the exact - # transient RestartSec=2 exists to wait out in production, so wait for it here too - # instead of failing the scenario on a cleanup race. + # Retry: an orphaned CoreDNS can still hold 169.254.10.10:53 for a moment. for cleanup_attempt in 1 2 3 4 5 6; do sudo systemctl is-active --quiet localdns.service && break sudo systemctl reset-failed localdns.service || true @@ -148,7 +222,7 @@ test "$control_group" = "/localdns.slice/localdns.service" || { exit 1 } -# Normal systemd stop must complete cleanup and return success. +# A normal stop must complete cleanup and return success. sudo systemctl restart localdns.service sudo systemctl is-active --quiet localdns.service sudo systemctl stop localdns.service @@ -156,27 +230,10 @@ test "$(sudo systemctl show localdns.service -p ActiveState --value)" = inactive sudo systemctl start localdns.service sudo systemctl is-active --quiet localdns.service -# Repeatedly kill the supervisor and wait for Restart=on-failure recovery. -# This verifies that systemd can restart LocalDNS; startup cleanup may restore -# DNS on this path, so it does not by itself validate the ExecStopPost fix. -# The terminal dead-service block below validates that fix directly. -# Require a genuinely new MainPID after each kill: immediately after kill -9, -# systemd may still report the killed invocation as active/running until it -# processes SIGCHLD, so checking active/running alone can observe the old -# process and falsely declare recovery. Save the killed PID and require the -# new MainPID to be nonzero and different from it. +# Kill the supervisor three times; each must recover with a new MainPID. test_start=$(date +%s) for i in 1 2 3; do - # Clear the start counter before each kill. The budget (StartLimitBurst=5 in any - # StartLimitIntervalSec=720 window) belongs to the unit and is shared by every actor - # that starts it -- CSE at provisioning, the validations above, and systemd's own - # Restart=on-failure. Without this, the starts already spent by the time we get here - # leave fewer than three slots, and the third kill's automatic restart is refused with - # "Start request repeated too quickly", so the service never returns and this loop - # fails for the wrong reason. What we are testing here is that Restart=on-failure - # recovers the service, not the rate limiter, so take the limiter out of the picture. - # restart_localdns_cleanly (validators.go) and the cleanup trap above do the same. sudo systemctl reset-failed localdns.service || true killed=$(sudo systemctl show -p MainPID --value localdns.service) test "$killed" -gt 0 @@ -195,13 +252,8 @@ for i in 1 2 3; do test "$recovered" = true done +# reset-failed zeroes NRestarts too, so this reports the final cycle only. restarts_after=$(sudo systemctl show localdns.service -p NRestarts --value) -# 'systemctl reset-failed' zeroes NRestarts as well as the start-limit counter, and the -# loop above resets before every kill, so this now reports the restarts from the final -# cycle only -- expect 1, not 3. The three cycles are already proven individually: each -# iteration requires "$recovered" = true, which demands a new, different MainPID, so a -# missed recovery fails there rather than here. This remains as a check that the last -# kill really was recovered by Restart=on-failure and not by something else. test "$restarts_after" -ge 1 || { echo "FAIL: expected >=1 systemd restart after the final kill, got $restarts_after" exit 1 @@ -212,16 +264,11 @@ printf '%s\n' "$state" printf '%s\n' "$state" | grep -q '^ActiveState=active$' printf '%s\n' "$state" | grep -q '^SubState=running$' printf '%s\n' "$state" | grep -q '^Result=success$' -# The cgroup teardown warning is diagnostic only: fixing it is out of scope for -# this PR (which is about restoring node DNS after an unexpected exit), so we -# surface it but do not fail on it. +# Diagnostic only; not failed on. if sudo journalctl -u localdns.service --since "@$test_start" --no-pager | grep -q 'Failed to kill control group'; then echo "WARNING: LocalDNS cgroup teardown warning observed" fi -# Three kills well inside the window must not exhaust the budget -- if they do, recovery -# from ordinary crashes is broken. Note this is scoped to the kill/recovery cycles above -# via --since: deliberately exhausting the budget is the expected outcome in the -# restart-budget validation, which runs separately after this function returns. +# Scoped by --since: budget exhaustion belongs to the restart-budget validation, not here. if sudo journalctl -u localdns.service --since "@$test_start" --no-pager | grep -q 'Start request repeated too quickly'; then echo "LocalDNS reached systemd StartLimit during the kill/recovery cycles" exit 1 @@ -229,20 +276,13 @@ fi dig +short +time=5 +tries=1 mcr.microsoft.com @169.254.10.10 | grep -q . if [ "$EXPECT_EXECSTOPPOST" = true ]; then -# The lane asked for this branch's VHD, so the hook must be there. Assert it rather than -# using its presence to decide whether to look -- a missing hook is the regression. +# Assert the hook; do not use its presence as permission to look. if ! sudo systemctl show localdns.service -p ExecStopPost --value | grep -q 'localdns.sh cleanup'; then echo "FAIL: ExecStopPost=localdns.sh cleanup is missing from localdns.service" sudo systemctl show localdns.service -p ExecStopPost || true exit 1 fi -# Terminal dead-service case: this is the incident scenario the PR fixes. -# When localdns ends up dead (systemd exhausts restart attempts), ExecStopPost -# must still revert node DNS so the node does not keep pointing at the dead -# localdns listener (169.254.10.10). We reach the dead state deterministically -# by disabling auto-restart with a transient drop-in, then killing the -# supervisor -- tripping StartLimit via rapid kills is timing dependent and -# flaky. ExecStopPost runs on the SIGKILL path regardless of Restart=. +# Terminal dead-service case: Restart=no drop-in, then one kill. sudo mkdir -p "$(dirname "$NORESTART")" printf '[Service]\nRestart=no\n' | sudo tee "$NORESTART" >/dev/null sudo systemctl daemon-reload @@ -251,11 +291,7 @@ dead_main=$(sudo systemctl show -p MainPID --value localdns.service) test "$dead_main" -gt 0 sudo kill -9 "$dead_main" -# Wait for the service to reach a terminal ActiveState (failed or inactive). -# A non-running SubState is not sufficient: SubState passes through transitional -# values such as stop-post while ExecStopPost is still running the cleanup under -# test, so asserting on drop-in removal then could race the cleanup. ActiveState -# only becomes failed/inactive after ExecStopPost has completed. +# ActiveState, not SubState: SubState passes through stop-post mid-cleanup. dead=false for attempt in 1 2 3 4 5 6 7 8 9 10 11 12; do active_state=$(sudo systemctl show localdns.service -p ActiveState --value) @@ -267,27 +303,13 @@ for attempt in 1 2 3 4 5 6 7 8 9 10 11 12; do done test "$dead" = true -# The localdns network drop-in must have been removed by ExecStopPost. This is -# the authoritative signal that DNS was reverted: the drop-in is what points the -# link's DNS at the localdns listener. -# 'sudo ls' rather than a bare ls: this is an assertion that concludes "absent" from a -# failed glob, so if the drop-in's directory were ever created root-only (as the test's own -# service drop-in dir is, under root's umask), an unprivileged ls would fail, the check -# would read that as success, and the regression under test would pass silently. The -# directory is 0755 today, but the assertion should not depend on that. +# sudo ls: "absent" concluded from a failed glob must not come from a permission error. if sudo ls /run/systemd/network/*.d/70-localdns.conf >/dev/null 2>&1; then echo "FAIL: 70-localdns.conf still present after localdns died" exit 1 fi -# The live link DNS must no longer include the localdns node listener. This is -# eventually consistent: networkctl reload propagates to systemd-resolved -# asynchronously, so poll (like wait_for_localdns_removed_from_resolv_conf does) -# until the listener IP is gone rather than checking once. Prefer resolvectl -# (the per-link view the drop-in configures); fall back to the resolved stub. -# Only accept a successful, non-empty resolver snapshot: an errored or empty -# read must not be treated as "restored", or a failed read would mask the very -# regression under test. Retry those instead. +# Poll: networkctl reload reaches systemd-resolved asynchronously. Empty reads are retried. dns_reverted=false resolver_state_readable=false localdns_listener_present=false @@ -322,8 +344,7 @@ if [ "$dns_reverted" != true ]; then exit 1 fi -# Removing the LocalDNS address is not sufficient: verify the node has a -# working resolver after cleanup. +# Address removal alone is not sufficient; the node must actually resolve. if ! getent hosts mcr.microsoft.com >/dev/null 2>&1; then echo "FAIL: node cannot resolve DNS after localdns died" exit 1 @@ -331,9 +352,5 @@ fi else echo "SKIP: this lane resolved a main-built image, which predates the ExecStopPost cleanup hook" fi - -# The EXIT trap removes the temporary override and restores LocalDNS even if -# an assertion above exits the validation early. -`, 0, "LocalDNS lifecycle validation failed") - return err +` } diff --git a/e2e/scenario/scenario_localdns_restart_budget.go b/e2e/scenario/scenario_localdns_restart_budget.go index e05a037ca86..3ddb59eadcb 100644 --- a/e2e/scenario/scenario_localdns_restart_budget.go +++ b/e2e/scenario/scenario_localdns_restart_budget.go @@ -640,6 +640,37 @@ func runLocalDNSFault(ctx context.Context, s *Scenario, fault localdnsFault) err } // localdnsFaultRunScript renders the per-fault script. +// +// # The ExecStart count is bounded on both sides, with deliberate slack +// +// Fewer starts than the burst means the unit gave up for some reason other than the +// limiter. Many more means the budget is not being enforced at all — which the journal +// refusal check cannot catch on its own, since a unit that restarted twenty times and then +// tripped the limiter still prints "Start request repeated too quickly". +// +// The upper bound is burst+1 rather than exactly burst. Copilot has twice recommended +// tightening it to equality; before doing so, note that the two measurements disagree: +// +// by hand, live node (PR #9439, 2026-09-17): postready = 6 ExecStarts, others 5 +// CI, gate build 181777373 (Ubuntu2404): postready = 5, every mode 5 +// +// The 6 has not been reproduced and nothing explains it. It is one observation from a real +// node, so tolerate it rather than ship a lane that flakes only when it recurs. The slack +// costs little — a limiter allowing exactly one extra start would pass — against a gate +// cycle lost to a flake. If you can explain or reproduce the 6, tighten this and record why +// here. Do not tighten it on the CI numbers alone; that is precisely what is in dispute. +// +// The hungstart count in that CI run is 6, but it is not evidence either way: +// measureLocalDNSWorstCycle runs the hungstart fault before the matrix, so journal lines for +// that mode conflate both phases. Only $COUNTER, cleared per fault, distinguishes them — +// anyone counting "E2EFAULT hungstart" in a journal will get a wrong answer. +// +// # Self-reference +// +// $burst is read from the live unit, so this compares the SUT against itself. That is only +// sound because assertLocalDNSBudgetDirectives has already pinned StartLimitBurst to 5 +// earlier in the same validation. If that assertion is removed, or reordered to after this +// point, this check silently stops meaning anything. func localdnsFaultRunScript(fault localdnsFault) string { return ` set -eu @@ -706,12 +737,17 @@ if ! sudo journalctl -u localdns.service --since "$since" --no-pager | grep -q ' exit 1 fi -# Exactly the burst should have run: more means the budget is not being enforced, fewer -# means the unit gave up for an unrelated reason. +# Bounded on both sides: [burst, burst+1]. See localdnsFaultRunScript's doc comment for +# why the upper bound has slack and why tightening it to equality needs new evidence. if [ "$starts" -lt "$burst" ]; then echo "FAIL: $LABEL ran $starts ExecStarts, expected at least the burst of $burst" exit 1 fi +if [ "$starts" -gt $((burst + 1)) ]; then + echo "FAIL: $LABEL ran $starts ExecStarts, expected at most the burst of $burst (+1 slack)." + echo " The limiter let the unit restart past its budget; it is not being enforced." + exit 1 +fi echo "OK: $LABEL terminated in 'failed' after $starts ExecStarts in ${elapsed}s" diff --git a/e2e/scenario/scenario_localdns_script_size_test.go b/e2e/scenario/scenario_localdns_script_size_test.go new file mode 100644 index 00000000000..3c97e2cced5 --- /dev/null +++ b/e2e/scenario/scenario_localdns_script_size_test.go @@ -0,0 +1,76 @@ +package scenario + +import ( + "fmt" + "testing" +) + +// bastionMaxScriptBytes is the largest script this package can send to a node. +// +// Scripts are SCP'd to the VM over the Bastion tunnel, and tunnelSession.Write +// (bastionssh.go) forwards whatever the SSH transport hands it as a single websocket +// message with no chunking. Azure Bastion caps an inbound message at 8,192 bytes and closes +// the tunnel with StatusMessageTooBig when one exceeds it — taking the whole scenario down +// mid-run, with no indication that script length was the cause. +// +// go-scp emits the file body as a 4,096-byte first chunk then the remainder in one write, +// so the largest wire write is: +// +// max_write = script_size - 4096 + 45 (45 = SSH framing + MAC) +// +// which first exceeds 8,192 at a script size of 12,243. The limit below is therefore the +// last safe size, measured by sweeping script sizes one byte at a time against a real +// x/crypto/ssh client and server. +// +// Gate build 181818040 lost three LocalDNS lanes to exactly this: the lifecycle script had +// been sitting 380 bytes under the cliff and grew 512 bytes, producing an 8,324-byte write. +// +// The right long-term fix is chunking in tunnelSession.Write, which is shared e2e +// infrastructure and out of scope here. Until that lands, this test is the guard. +const bastionMaxScriptBytes = 12242 + +// TestLocalDNSScriptsFitBastionLimit fails the build when any script this package sends +// would kill the Bastion tunnel. +// +// It covers every script, not just the one that broke, because the failure mode gives no +// hint about its cause: the scenario dies with a websocket close frame and loses its node +// logs, so whoever hits it next starts from "the node became unreachable" rather than +// "my script got too long". Cheaper to fail here. +// +// If a script does outgrow the limit, prefer moving its comments into Go — they cost the +// same on the wire as code and buy nothing at runtime. validateLocalDNSLifecycle's doc +// comment is the worked example. +func TestLocalDNSScriptsFitBastionLimit(t *testing.T) { + scripts := map[string]string{ + "lifecycle(true)": localdnsLifecycleScript("true"), + "lifecycle(false)": localdnsLifecycleScript("false"), + "localdnsDirectiveAssertScript": localdnsDirectiveAssertScript, + "localdnsWorstCycleScript": localdnsWorstCycleScript, + "localdnsProvisioningRestartScript": localdnsProvisioningRestartScript, + "localdnsFaultHarnessInstallScript": localdnsFaultHarnessInstallScript, + "localdnsFaultTeardownScript": localdnsFaultTeardownScript, + } + for _, fault := range localdnsFaultMatrix { + scripts["localdnsFaultRunScript/"+fault.name] = localdnsFaultRunScript(fault) + } + + for name, script := range scripts { + if len(script) > bastionMaxScriptBytes { + t.Errorf( + "%s is %d bytes, over the %d-byte Bastion tunnel limit by %d.\n"+ + "This will not fail as a size error: the tunnel closes with "+ + "StatusMessageTooBig, the scenario reports a dead SSH session, and node log "+ + "collection fails too. Move the script's comments into Go rather than "+ + "deleting them — they cost the same on the wire and do nothing at runtime.", + name, len(script), bastionMaxScriptBytes, len(script)-bastionMaxScriptBytes, + ) + } + } + + if t.Failed() || testing.Verbose() { + for name, script := range scripts { + fmt.Printf(" %-46s %6d bytes (%d headroom)\n", + name, len(script), bastionMaxScriptBytes-len(script)) + } + } +} From 2db8a901429ac0e421b7f9e7414cb516914eca52 Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Mon, 21 Sep 2026 19:56:15 +0000 Subject: [PATCH 24/26] fix: set TimeoutStopFailureMode in the drop-in, where systemd will honour it fbe622a10 pinned TimeoutStopFailureMode=terminate in localdns.service. It has no effect there. systemd.unit(5): "Drop-in files under any of these directories take precedence over unit files wherever located." Azure Linux ships a type-wide drop-in at /usr/lib/systemd/system/service.d/10-timeout-abort.conf (systemd.spec line 893) setting TimeoutStopFailureMode=abort, so the unit file loses and the effective value on AzureLinuxV3 stayed 'abort'. Which means the cycle stayed at the 153s that pin was written to avoid -- above the 144s threshold, so the slow failure modes would restart forever on that distro. Exactly the bug this PR exists to remove, reintroduced by the fix for it. Reproduced and fixed with the real files rather than a synthetic unit: unit file only -> terminate + /usr/lib/.../service.d/10-abort drop-in -> abort <- the bug + localdns.service.d/delegate.conf -> terminate <- the fix Effective budget afterwards: Restart=on-failure, RestartUSec=2s, TimeoutStartUSec=1min 30s, TimeoutStopUSec=30s, TimeoutStopFailureMode=terminate, StartLimitIntervalUSec=12min, StartLimitBurst=5, Delegate=yes/cpu. Worst cycle 90+30+2 = 122s against the 144s threshold, on every image. localdns-delegate.conf is the right home because it is already a unit-specific drop-in for this unit, already installed to /etc/systemd/system/localdns.service.d/delegate.conf by packer_source.sh, and already shipped by all nine packer definitions plus azlosguard.yml. A new drop-in file would mean editing each of those, where missing one ships an image without it and fails silently months later on one distro. The cost is that a file named for Delegate=cpu now also carries a stop-timeout directive; mitigated by the comment there and a pointer from localdns.service, and a rename is a standalone change if it is wanted. The e2e assertion is unchanged and was right all along: it reads the effective value via systemctl show, so it does not care which file sets it. Credit to @yewmsft for catching that the pin could not work where it was. Co-Authored-By: Claude Opus 5 (1M context) --- .../artifacts/localdns-delegate.conf | 30 +++++++++++++++++- .../cloud-init/artifacts/localdns.service | 31 +++++-------------- 2 files changed, 36 insertions(+), 25 deletions(-) diff --git a/parts/linux/cloud-init/artifacts/localdns-delegate.conf b/parts/linux/cloud-init/artifacts/localdns-delegate.conf index 8fd08355ca5..eb691a66c86 100644 --- a/parts/linux/cloud-init/artifacts/localdns-delegate.conf +++ b/parts/linux/cloud-init/artifacts/localdns-delegate.conf @@ -1,2 +1,30 @@ [Service] -Delegate=cpu \ No newline at end of file +# Makes systemd enable the cpu controller in this unit's cgroup subtree, so +# /sys/fs/cgroup/localdns.slice/localdns.service/cpu.stat exists for the CPU metrics +# localdns.sh exports. +Delegate=cpu + +# Pinned here rather than in localdns.service, because it cannot work there. +# +# Azure Linux ships a type-wide drop-in at +# /usr/lib/systemd/system/service.d/10-timeout-abort.conf setting +# TimeoutStopFailureMode=abort (Fedora's "Shorter Shutdown Timer"), and systemd.unit(5) +# states drop-ins take precedence over unit files wherever located. Verified with the real +# files: unit file alone -> terminate; plus the type-wide 10- file -> abort; plus this +# drop-in -> terminate. +# +# With abort in effect a stop timeout sends SIGABRT to capture a core dump, then waits a +# SECOND TimeoutStopSec in 'stop-watchdog' before SIGKILL, doubling the stop side of the +# restart cycle. Measured on AzureLinuxV3: 90 + 30 + 30 + 2 = 153s, above the 144s +# threshold (StartLimitIntervalSec/StartLimitBurst), so the slow failure modes would +# restart forever there -- exactly what the budget exists to prevent. Pinned back to the +# systemd default the cycle is 90 + 30 + 2 = 122s on every image we ship. +# +# The core dump the abort step exists to produce is already discarded on AKS nodes: +# configureCoreDump() in cis.sh sets Storage=none and ProcessSizeMax=0 for every distro +# (it runs before the Mariner/AzureLinux early return in applyCIS), asserted by +# testCoreDumpSettings in linux-vhd-content-test.sh. So today that step costs 30s of +# restart cycle and produces nothing. If that hardening is ever relaxed, revisit this -- +# the 30s would have to be bought back elsewhere in the cycle or the threshold widened, or +# Azure Linux goes back over 144s. +TimeoutStopFailureMode=terminate diff --git a/parts/linux/cloud-init/artifacts/localdns.service b/parts/linux/cloud-init/artifacts/localdns.service index b469e350453..fd6f010ab80 100644 --- a/parts/linux/cloud-init/artifacts/localdns.service +++ b/parts/linux/cloud-init/artifacts/localdns.service @@ -10,9 +10,9 @@ ConditionKernelVersion=>=5.15 # Bound the restart budget so every unrecoverable failure mode terminates in # 'failed' rather than restarting forever. The threshold is # StartLimitIntervalSec/StartLimitBurst = 720/5 = 144s, just above the slowest -# restart cycle (~122s = TimeoutStartSec 90 + TimeoutStopSec 30 + RestartSec 2, all -# pinned below -- including TimeoutStopFailureMode, without which Azure Linux spends two -# stop timeouts and the cycle is 153s, above the threshold), +# restart cycle (~122s = TimeoutStartSec 90 + TimeoutStopSec 30 + RestartSec 2, pinned +# below, plus TimeoutStopFailureMode=terminate pinned in the drop-in -- without which +# Azure Linux spends two stop timeouts and the cycle is 153s, above the threshold), # so slow failures (PID file never appears, watchdog kill, ready-check timeout, # hung start) still reach 'failed'. That terminal state is what lets an # OnFailure= handoff fire and gives NPD a stable state to observe. @@ -54,27 +54,10 @@ ExecStopPost=/opt/azure/containers/localdns/localdns.sh cleanup # DefaultTimeoutStartSec would move it silently. TimeoutStartSec=90 TimeoutStopSec=30 -# Pinned for the same reason, and measured rather than assumed. Azure Linux ships a global -# drop-in at /usr/lib/systemd/system/service.d/10-timeout-abort.conf setting -# TimeoutStopFailureMode=abort (Fedora's "Shorter Shutdown Timer"): on a stop timeout systemd -# sends SIGABRT to capture a core dump, then waits a SECOND TimeoutStopSec in 'stop-watchdog' -# before SIGKILL. That doubles the stop side of the restart cycle. Measured on AzureLinuxV3: -# 90 + 30 + 30 + 2 = 153s, above the 144s threshold -- so the slow modes would restart forever -# there, which is exactly what this budget exists to prevent. 'terminate' is the systemd -# default; pinning it makes the cycle 90 + 30 + 2 = 122s on every image we ship. -# -# The core dump that step exists to produce is already discarded on AKS nodes: -# configureCoreDump() in parts/linux/cloud-init/artifacts/cis.sh sets Storage=none and -# ProcessSizeMax=0, applied to every distro (it runs before the Mariner/AzureLinux early -# return in applyCIS), and asserted by testCoreDumpSettings in -# vhdbuilder/packer/test/linux-vhd-content-test.sh. So today the abort step costs 30s of -# restart cycle and produces nothing. -# -# If that hardening is ever relaxed -- Storage= set to anything but none, or ProcessSizeMax -# raised -- revisit this directive. The abort step would start producing a usable dump, and -# the 30s it costs would have to be bought back elsewhere in the cycle or the threshold -# widened, or Azure Linux goes back over 144s. -TimeoutStopFailureMode=terminate +# TimeoutStopFailureMode is pinned too, but it cannot be set here: Azure Linux ships a +# type-wide drop-in that overrides unit files. It lives in localdns-delegate.conf, +# installed as /etc/systemd/system/localdns.service.d/delegate.conf -- see the comment +# there for why, and for the 153s cycle it prevents. Slice=localdns.slice EnvironmentFile=-/etc/localdns/environment ExecStart=/opt/azure/containers/localdns/localdns.sh From 5403638969f953c77a09591e5bacf8f7a4526826 Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Mon, 21 Sep 2026 19:56:15 +0000 Subject: [PATCH 25/26] test(e2e): address review on the script-size guard and the provisioning loop Five review items from @yewmsft. 1. The Bastion size constant was justified two ways that land a byte apart. The sweep is the measurement and the formula is a model: 12,242 is safe and 12,243 produced an 8,196-byte write, where the formula predicts 8,192. It ignores SSH block padding, so writes step rather than increment. Comment now says to trust the sweep and not to "correct" the constant upward from the arithmetic. 2. "Covers every script" was only true of the ones someone remembered to add to the map. TestLocalDNSScriptInventoryIsRegistered now derives the inventory from the source and fails the build when a declared localdns*Script is not size-checked. Mutation-tested: declaring an unregistered script fails it. 3. 'if ! retrycmd_if_failure ...' discarded the return code. '!' inverts before $? is read, so a CSE budget timeout (2) and a genuine failure (1) both reported as "could not be enabled by systemctl", sending the on-call after systemd when the cause was provisioning running out of time. Captured and distinguished, matching what localdns_giveup_reason already does for the start loop. ShellSpec covers the new path; mutation-tested against the old form. 4. The 100-attempt count named a ceiling the loop cannot reach -- check_cse_timeout reaches its limit first in any realistic run. Dropped the ceiling language from the give-up reason and the per-attempt message rather than substituting another invented number, and said so where the constant is declared. 5. Hoisted daemon-reload above the loop. Nothing rewrites a unit between iterations, and it re-parses every unit on the box. Fair catch that the same cost argument was applied to the helper's per-attempt dumps but not its reload. Co-Authored-By: Claude Opus 5 (1M context) --- .../scenario_localdns_script_size_test.go | 47 +++++++++++++++++-- .../artifacts/cse_config_localdns.sh | 32 +++++++++---- .../artifacts/cse_config_localdns_spec.sh | 20 ++++++-- 3 files changed, 84 insertions(+), 15 deletions(-) diff --git a/e2e/scenario/scenario_localdns_script_size_test.go b/e2e/scenario/scenario_localdns_script_size_test.go index 3c97e2cced5..3457375351a 100644 --- a/e2e/scenario/scenario_localdns_script_size_test.go +++ b/e2e/scenario/scenario_localdns_script_size_test.go @@ -2,6 +2,8 @@ package scenario import ( "fmt" + "os" + "regexp" "testing" ) @@ -18,9 +20,12 @@ import ( // // max_write = script_size - 4096 + 45 (45 = SSH framing + MAC) // -// which first exceeds 8,192 at a script size of 12,243. The limit below is therefore the -// last safe size, measured by sweeping script sizes one byte at a time against a real -// x/crypto/ssh client and server. +// The constant below is the last safe size, and it comes from measurement, not from that +// formula: sweeping script sizes one byte at a time against a real x/crypto/ssh client and +// server, 12,242 is safe and 12,243 produced an 8,196-byte write. The formula predicts +// 8,192 at that size, which would not exceed the cap -- it is an approximation that ignores +// SSH block padding, so writes step rather than increment and arithmetic on it lands a byte +// off. Trust the sweep. Do not "correct" the constant upward from the formula. // // Gate build 181818040 lost three LocalDNS lanes to exactly this: the lifecycle script had // been sitting 380 bytes under the cliff and grew 512 bytes, producing an 8,324-byte write. @@ -74,3 +79,39 @@ func TestLocalDNSScriptsFitBastionLimit(t *testing.T) { } } } + +// TestLocalDNSScriptInventoryIsRegistered fails the build when a script is declared but not +// size-checked. +// +// TestLocalDNSScriptsFitBastionLimit covers every script someone remembered to add to its +// map, which is not the same thing. An eighth script lands silently, and the failure it then +// hits is the one with no diagnostic attached — a dead tunnel and no node logs. So derive +// the inventory from the source rather than restating it. +func TestLocalDNSScriptInventoryIsRegistered(t *testing.T) { + // Keyed by declaration name, not by the map keys in the size test — those are free to be + // whatever reads best there ("lifecycle(true)", "localdnsFaultRunScript/preflight"). + registered := map[string]bool{ + "localdnsLifecycleScript": true, + "localdnsDirectiveAssertScript": true, + "localdnsWorstCycleScript": true, + "localdnsProvisioningRestartScript": true, + "localdnsFaultHarnessInstallScript": true, + "localdnsFaultTeardownScript": true, + "localdnsFaultRunScript": true, + } + declaration := regexp.MustCompile(`(?m)^(?:var|const|func) (localdns\w*Script)\b`) + for _, file := range []string{"scenario_localdns_hosts.go", "scenario_localdns_restart_budget.go"} { + src, err := os.ReadFile(file) + if err != nil { + t.Fatalf("read %s: %v", file, err) + } + for _, match := range declaration.FindAllStringSubmatch(string(src), -1) { + if !registered[match[1]] { + t.Errorf("%s is declared in %s but is not size-checked by "+ + "TestLocalDNSScriptsFitBastionLimit. Add it to that test's map and to the "+ + "registered set here, or it can outgrow the Bastion limit unnoticed.", + match[1], file) + } + } + } +} diff --git a/parts/linux/cloud-init/artifacts/cse_config_localdns.sh b/parts/linux/cloud-init/artifacts/cse_config_localdns.sh index d6aee52884a..0995bbea421 100644 --- a/parts/linux/cloud-init/artifacts/cse_config_localdns.sh +++ b/parts/linux/cloud-init/artifacts/cse_config_localdns.sh @@ -115,9 +115,10 @@ enableLocalDNS() { # clears start_ratelimit on systemd 249 but not on 255 (Ubuntu 24.04). local localdns_started=false local i - # 100 attempts at 5s matches what systemctlEnableAndStart did before (systemctl_restart - # 100 5 30, cse_helpers.sh), so the provisioning recovery window is unchanged -- a fast - # transient still gets ~10 minutes to clear. check_cse_timeout bounds the slow case: if + # 100 matches what systemctlEnableAndStart did before (systemctl_restart 100 5 30, + # cse_helpers.sh), but it is a backstop rather than a budget: check_cse_timeout below + # reaches its limit first in any realistic run, so the loop ends on the CSE deadline, + # not on the count. Do not reason about the loop's duration from 100. check_cse_timeout bounds the slow case: if # every restart hangs for its full 30s timeout, this loop would outlive CSE's 15m kill in # cse_start.sh and be SIGKILLed mid-iteration, losing the status log and the exit code # below. Breaking out early lets the give-up path run and report properly, matching the @@ -127,14 +128,18 @@ enableLocalDNS() { # These all talk to PID 1 over D-Bus; an unbounded one that wedges would never return to # the top of the loop, so check_cse_timeout above would never be re-evaluated and CSE # would be SIGKILLed before it could report. - local localdns_giveup_reason="exhausted 100 restart attempts" + local localdns_giveup_reason="exhausted the restart attempts" + # Hoisted out of the loop: nothing here rewrites a unit between iterations, and + # daemon-reload re-parses every unit on the box. _systemctl_retry_svc_operation did it + # per attempt, but the point of inlining this loop was to stop paying for what that + # helper did blindly. + timeout 30 systemctl daemon-reload for i in $(seq 1 100); do if ! check_cse_timeout; then localdns_giveup_reason="CSE provisioning budget exhausted at attempt ${i}" break fi timeout 30 systemctl reset-failed localdns 2>/dev/null || true - timeout 30 systemctl daemon-reload if timeout 30 systemctl restart localdns; then localdns_started=true break @@ -146,7 +151,7 @@ enableLocalDNS() { # only record of what was going wrong across the retries, so sample it instead: every # tenth attempt, with the journal bounded by -n. if [ $((i % 10)) -eq 0 ]; then - echo "localdns restart attempt ${i}/100 failed; unit state and recent journal follow." + echo "localdns restart attempt ${i} failed; unit state and recent journal follow." timeout 30 systemctl status localdns --no-pager -l || true timeout 30 journalctl -u localdns --no-pager -n 50 || true fi @@ -169,8 +174,19 @@ enableLocalDNS() { # Log on this path too. systemctlEnableAndStart wrote a status log when 'systemctl enable' # failed as well as when the start failed; inlining the loop kept the start path and dropped # this one, so an enable failure exited with nothing but the code. - if ! retrycmd_if_failure 120 5 25 systemctl enable localdns; then - echo "localdns could not be enabled by systemctl." + # Capture the code rather than using 'if ! ...': '!' inverts before $? is read, so the + # distinction is gone inside the then-block. retrycmd_if_failure returns 2 when + # check_cse_timeout trips (cse_helpers.sh:270, :298) and 1 when it genuinely exhausts + # its attempts. Reporting the first as a systemd failure sends the on-call after the + # wrong thing -- same reason localdns_giveup_reason exists for the start loop above. + retrycmd_if_failure 120 5 25 systemctl enable localdns + local enable_rc=$? + if [ "$enable_rc" -ne 0 ]; then + if [ "$enable_rc" -eq 2 ]; then + echo "localdns could not be enabled: CSE provisioning budget exhausted." + else + echo "localdns could not be enabled by systemctl." + fi timeout 30 systemctl status localdns --no-pager -l > /var/log/azure/localdns-status.log || true timeout 30 journalctl -u localdns --no-pager -n 200 >> /var/log/azure/localdns-status.log || true exit $ERR_LOCALDNS_FAIL diff --git a/spec/parts/linux/cloud-init/artifacts/cse_config_localdns_spec.sh b/spec/parts/linux/cloud-init/artifacts/cse_config_localdns_spec.sh index 6154a31bccc..64099f736ef 100755 --- a/spec/parts/linux/cloud-init/artifacts/cse_config_localdns_spec.sh +++ b/spec/parts/linux/cloud-init/artifacts/cse_config_localdns_spec.sh @@ -173,7 +173,7 @@ Describe 'cse_config_localdns.sh' tracing_systemctl When run enableLocalDNS The status should equal 216 - The output should include "localdns could not be started: exhausted 100 restart attempts." + The output should include "localdns could not be started: exhausted the restart attempts." The contents of file /var/log/azure/localdns-status.log should include "journalctl -u localdns" End @@ -186,7 +186,7 @@ Describe 'cse_config_localdns.sh' When run enableLocalDNS The status should equal 216 The output should include "CSE provisioning budget exhausted at attempt 1" - The output should not include "exhausted 100 restart attempts" + The output should not include "exhausted the restart attempts" End It 'should sample diagnostics during the retries without dumping on every attempt' @@ -197,9 +197,9 @@ Describe 'cse_config_localdns.sh' tracing_systemctl When run enableLocalDNS The status should be success - The output should include "localdns restart attempt 10/100 failed" + The output should include "localdns restart attempt 10 failed" The output should include "journalctl -u localdns --no-pager -n 50" - The output should not include "localdns restart attempt 9/100 failed" + The output should not include "localdns restart attempt 9 failed" The output should include "Enable localdns succeeded." End @@ -214,6 +214,18 @@ Describe 'cse_config_localdns.sh' The output should not include "Enable localdns succeeded." The contents of file /var/log/azure/localdns-status.log should include "journalctl -u localdns" End + + It 'should distinguish a CSE budget timeout from a genuine enable failure' + # retrycmd_if_failure returns 2 when check_cse_timeout trips and 1 when it burns + # all its attempts. 'if ! retrycmd ...' would throw that away -- '!' inverts before + # $? is read -- and report a budget timeout as a systemd failure, sending the + # on-call after the wrong thing. + retrycmd_if_failure() { return 2; } + When run enableLocalDNS + The status should equal 216 + The output should include "localdns could not be enabled: CSE provisioning budget exhausted." + The output should not include "could not be enabled by systemctl" + End End Describe 'enableLocalDNSForScriptless' setup() { From 2dc4c71a91234c49a4062cb4ae09367faacbdcdf Mon Sep 17 00:00:00 2001 From: Saewon Kwak <23280628+saewoni@users.noreply.github.com> Date: Mon, 21 Sep 2026 21:50:47 +0000 Subject: [PATCH 26/26] test(e2e): replace the size-limit formula with the measurement, and unify the inventory Four review items from @yewmsft. 1. The Bastion size comment named a mechanism I had not isolated, and got it wrong twice. Ye pointed out SSH pads each binary packet to a multiple of the cipher block size, so a 1-byte script change moves the wire write by 0 or 16 -- never by the 5 the comment claimed. Swept the range again and pasted the rows: 12236..12242 -> 8180 12243..12248 -> 8196 <- first over 8,192 A clean 16-byte step, and no script size lands on 8,192 at all. That also retires max_write = size - 4096 + 45, which is off by 11 at the plateau and implies a granularity the transport does not have. The constant 12242 was right; only the explanation beside it was wrong. Data now, not a story -- measured rows survive the next person doing arithmetic at 2am. 2. The inventory guard closed the gap one step short. 'registered' and the size test's 'scripts' were two hand-maintained lists with nothing tying them together, so declaring a script and adding it to one but not the other left both tests green and the script unchecked -- the same failure the guard exists to prevent, moved up a level. My own error message asked for two edits and verified one. localdnsScriptsUnderTest is now the single inventory both read, so registering and size-checking are one edit. Mutation-tested with exactly that scenario. 3. The scanned file list was the inventory restated a third time, and missed validate_localdns_exporter_metrics.go. Replaced with filepath.Glob("*.go") -- go test runs in the package dir, so new scenario files are covered on arrival. Recorded the gap it still cannot close: the regex keys on the localdns*Script naming convention, so a script sent under another name stays unguarded. 4. Rewrapped the spliced comment in cse_config_localdns.sh and split the check_cse_timeout argument, which was being made twice in four lines. Co-Authored-By: Claude Opus 5 (1M context) --- .../scenario_localdns_script_size_test.go | 92 +++++++++++-------- .../artifacts/cse_config_localdns.sh | 16 ++-- 2 files changed, 65 insertions(+), 43 deletions(-) diff --git a/e2e/scenario/scenario_localdns_script_size_test.go b/e2e/scenario/scenario_localdns_script_size_test.go index 3457375351a..aef6b386f3c 100644 --- a/e2e/scenario/scenario_localdns_script_size_test.go +++ b/e2e/scenario/scenario_localdns_script_size_test.go @@ -3,6 +3,7 @@ package scenario import ( "fmt" "os" + "path/filepath" "regexp" "testing" ) @@ -15,17 +16,17 @@ import ( // the tunnel with StatusMessageTooBig when one exceeds it — taking the whole scenario down // mid-run, with no indication that script length was the cause. // -// go-scp emits the file body as a 4,096-byte first chunk then the remainder in one write, -// so the largest wire write is: +// The constant below is the last safe script size, measured by sweeping sizes one byte at a +// time against a real x/crypto/ssh client and server. SSH pads each binary packet up to a +// multiple of the cipher block size, so the wire write plateaus and then steps -- there is +// no script size that lands exactly on the 8,192 cap: // -// max_write = script_size - 4096 + 45 (45 = SSH framing + MAC) +// 12236..12242 -> 8180 +// 12243..12248 -> 8196 <- first over 8,192 // -// The constant below is the last safe size, and it comes from measurement, not from that -// formula: sweeping script sizes one byte at a time against a real x/crypto/ssh client and -// server, 12,242 is safe and 12,243 produced an 8,196-byte write. The formula predicts -// 8,192 at that size, which would not exceed the cap -- it is an approximation that ignores -// SSH block padding, so writes step rather than increment and arithmetic on it lands a byte -// off. Trust the sweep. Do not "correct" the constant upward from the formula. +// Do not derive this constant arithmetically from the script size. An earlier version of +// this comment did exactly that and was wrong twice: off by 11 bytes at the plateau, and +// implying a 1-byte granularity the transport does not have. // // Gate build 181818040 lost three LocalDNS lanes to exactly this: the lifecycle script had // been sitting 380 bytes under the cliff and grew 512 bytes, producing an 8,324-byte write. @@ -45,18 +46,38 @@ const bastionMaxScriptBytes = 12242 // If a script does outgrow the limit, prefer moving its comments into Go — they cost the // same on the wire as code and buy nothing at runtime. validateLocalDNSLifecycle's doc // comment is the worked example. -func TestLocalDNSScriptsFitBastionLimit(t *testing.T) { - scripts := map[string]string{ - "lifecycle(true)": localdnsLifecycleScript("true"), - "lifecycle(false)": localdnsLifecycleScript("false"), - "localdnsDirectiveAssertScript": localdnsDirectiveAssertScript, - "localdnsWorstCycleScript": localdnsWorstCycleScript, - "localdnsProvisioningRestartScript": localdnsProvisioningRestartScript, - "localdnsFaultHarnessInstallScript": localdnsFaultHarnessInstallScript, - "localdnsFaultTeardownScript": localdnsFaultTeardownScript, - } +// localdnsScriptsUnderTest is the single inventory of scripts this package sends to a node, +// keyed by declaration name. Both tests below read it, so registering a script and +// size-checking it are the same edit -- there is no way to do one without the other. +// +// Two lists would not be equivalent: a script added to one and missed in the other passes +// both tests while going unchecked, which is the exact failure this is here to prevent. +func localdnsScriptsUnderTest() map[string][]string { + faultRunScripts := make([]string, 0, len(localdnsFaultMatrix)) for _, fault := range localdnsFaultMatrix { - scripts["localdnsFaultRunScript/"+fault.name] = localdnsFaultRunScript(fault) + faultRunScripts = append(faultRunScripts, localdnsFaultRunScript(fault)) + } + return map[string][]string{ + "localdnsLifecycleScript": {localdnsLifecycleScript("true"), localdnsLifecycleScript("false")}, + "localdnsDirectiveAssertScript": {localdnsDirectiveAssertScript}, + "localdnsWorstCycleScript": {localdnsWorstCycleScript}, + "localdnsProvisioningRestartScript": {localdnsProvisioningRestartScript}, + "localdnsFaultHarnessInstallScript": {localdnsFaultHarnessInstallScript}, + "localdnsFaultTeardownScript": {localdnsFaultTeardownScript}, + "localdnsFaultRunScript": faultRunScripts, + } +} + +func TestLocalDNSScriptsFitBastionLimit(t *testing.T) { + scripts := map[string]string{} + for declaration, rendered := range localdnsScriptsUnderTest() { + for i, script := range rendered { + name := declaration + if len(rendered) > 1 { + name = fmt.Sprintf("%s[%d]", declaration, i) + } + scripts[name] = script + } } for name, script := range scripts { @@ -88,28 +109,27 @@ func TestLocalDNSScriptsFitBastionLimit(t *testing.T) { // hits is the one with no diagnostic attached — a dead tunnel and no node logs. So derive // the inventory from the source rather than restating it. func TestLocalDNSScriptInventoryIsRegistered(t *testing.T) { - // Keyed by declaration name, not by the map keys in the size test — those are free to be - // whatever reads best there ("lifecycle(true)", "localdnsFaultRunScript/preflight"). - registered := map[string]bool{ - "localdnsLifecycleScript": true, - "localdnsDirectiveAssertScript": true, - "localdnsWorstCycleScript": true, - "localdnsProvisioningRestartScript": true, - "localdnsFaultHarnessInstallScript": true, - "localdnsFaultTeardownScript": true, - "localdnsFaultRunScript": true, - } + registered := localdnsScriptsUnderTest() declaration := regexp.MustCompile(`(?m)^(?:var|const|func) (localdns\w*Script)\b`) - for _, file := range []string{"scenario_localdns_hosts.go", "scenario_localdns_restart_budget.go"} { + // Glob rather than a literal file list: go test runs in the package directory, so this + // covers new scenario files on arrival instead of only when someone remembers to add + // them here. Known gap it cannot close -- the regex keys on the localdns*Script naming + // convention, so a script sent through execScriptOnVMForScenario* under another name is + // still unguarded (validate_localdns_exporter_metrics.go does this today). + files, err := filepath.Glob("*.go") + if err != nil { + t.Fatal(err) + } + for _, file := range files { src, err := os.ReadFile(file) if err != nil { t.Fatalf("read %s: %v", file, err) } for _, match := range declaration.FindAllStringSubmatch(string(src), -1) { - if !registered[match[1]] { - t.Errorf("%s is declared in %s but is not size-checked by "+ - "TestLocalDNSScriptsFitBastionLimit. Add it to that test's map and to the "+ - "registered set here, or it can outgrow the Bastion limit unnoticed.", + if _, ok := registered[match[1]]; !ok { + t.Errorf("%s is declared in %s but is not in localdnsScriptsUnderTest, so it is "+ + "never size-checked and can outgrow the Bastion limit unnoticed. Add it "+ + "there -- that one edit both registers and size-checks it.", match[1], file) } } diff --git a/parts/linux/cloud-init/artifacts/cse_config_localdns.sh b/parts/linux/cloud-init/artifacts/cse_config_localdns.sh index 0995bbea421..d5aff6cb235 100644 --- a/parts/linux/cloud-init/artifacts/cse_config_localdns.sh +++ b/parts/linux/cloud-init/artifacts/cse_config_localdns.sh @@ -116,13 +116,15 @@ enableLocalDNS() { local localdns_started=false local i # 100 matches what systemctlEnableAndStart did before (systemctl_restart 100 5 30, - # cse_helpers.sh), but it is a backstop rather than a budget: check_cse_timeout below - # reaches its limit first in any realistic run, so the loop ends on the CSE deadline, - # not on the count. Do not reason about the loop's duration from 100. check_cse_timeout bounds the slow case: if - # every restart hangs for its full 30s timeout, this loop would outlive CSE's 15m kill in - # cse_start.sh and be SIGKILLed mid-iteration, losing the status log and the exit code - # below. Breaking out early lets the give-up path run and report properly, matching the - # other retry loops in cse_helpers.sh. + # cse_helpers.sh), but it is a backstop, not a budget. check_cse_timeout below reaches + # its limit first in any realistic run, so the loop ends on the CSE deadline rather than + # on the count -- do not reason about the loop's duration from 100. + # + # That guard is what keeps the slow case safe: if every restart hangs for its full 30s + # timeout, the loop would outlive CSE's 15m kill in cse_start.sh and be SIGKILLed + # mid-iteration, losing the status log and the exit code below. Breaking out early lets + # the give-up path run and report properly, matching the other retry loops in + # cse_helpers.sh. # # Every systemd call here is wrapped in timeout, as _systemctl_retry_svc_operation did. # These all talk to PID 1 over D-Bus; an unbounded one that wedges would never return to