fix: bound LocalDNS restart budget so failures terminate deterministically

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))
+	}
+}

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))
+		}
+	}
+}

parts/linux/cloud-init/artifacts/cse_config_localdns.sh

@@ -107,7 +107,74 @@ 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
+    # 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.
+    #
+    # 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.
+    local localdns_giveup_reason="exhausted 100 restart attempts"
+    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
+        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
     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.

parts/linux/cloud-init/artifacts/localdns.service

@@ -7,16 +7,74 @@ 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 (~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.
+#
+# 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
 
 [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
+# 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
+# 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