daemon: detect host suspend and recover the transport on resume

pkg/daemon/rxwatchdog.go

@@ -48,6 +48,17 @@ const (
 	// rxWatchdogTickInterval is how often the watchdog samples counters.
 	rxWatchdogTickInterval = 30 * time.Second
 
+	// suspendGapThreshold is how late a tick must be before the watchdog
+	// concludes this process was not running — a laptop sleeping, a paused
+	// VM, a migrated hypervisor guest.
+	//
+	// 4x the tick interval: far beyond scheduler jitter or a slow tick, but
+	// still under the shortest realistic lid-close. Deliberately measured
+	// from observed ticker lateness rather than any OS power API, so it
+	// works identically on macOS, Linux and inside a VM, and needs no
+	// platform-specific code (there was none in the tree at all).
+	suspendGapThreshold = 4 * rxWatchdogTickInterval
+
 	// rxSilenceThreshold is how long PktsRecv must stall (with tx active)
 	// before the first soft recovery fires.
 	rxSilenceThreshold = 3 * time.Minute
@@ -113,6 +124,19 @@ type rxWatchdogState struct {
 	recvSeen       uint64    // PktsRecv at lastProgress
 	sentAtProgress uint64    // PktsSent at lastProgress
 	softAttempts   int       // consecutive soft recoveries this silence
+
+	// suspendSeen records that the host suspended during this process's
+	// lifetime. It permanently unlocks the "never progressed" guard.
+	//
+	// That guard withholds the hard exit when PktsRecv has not advanced
+	// once this process, on the theory that restarting would reproduce the
+	// same state and boot-loop. Sound for a host that never had working
+	// inbound — and wrong after a resume, where the transport worked
+	// before the gap and a restart is exactly what recovers it. In the
+	// field this guard was the dominant blocker: of 344 withheld restarts
+	// on one laptop, 301 were "never progressed" and only 4 were the
+	// registry check.
+	suspendSeen bool
 }
 
 // rxWatchdogAction names what a tick did — returned for tests and logs.
@@ -143,16 +167,83 @@ func (d *Daemon) rxWatchdogLoop() {
 	}
 	ticker := time.NewTicker(rxWatchdogTickInterval)
 	defer ticker.Stop()
+	lastTick := time.Now()
 	for {
 		select {
 		case <-d.stopCh:
 			return
 		case <-ticker.C:
-			d.rxWatchdogTick(st, time.Now())
+			now := time.Now()
+			if gap := now.Sub(lastTick); gap >= suspendGapThreshold {
+				d.rxWatchdogResume(st, now, gap)
+			}
+			lastTick = now
+			d.rxWatchdogTick(st, now)
 		}
 	}
 }
 
+// rxWatchdogResume handles coming back from a host suspend (laptop lid
+// closed, VM paused, hypervisor migration).
+//
+// This is the gap the watchdog had. On resume every UDP path is stale —
+// the NAT mapping the beacon punched is gone, the peer sessions are dead,
+// and the pooled registry conn is half-open. Nothing in the daemon noticed:
+// there was no suspend/resume awareness anywhere in the tree (no
+// IORegisterForSystemPower, no wake notification, nothing), so recovery had
+// to wait for the ordinary rx-silence path — which then deadlocked against
+// its own safety guard (see the active probe in rxWatchdogTick).
+//
+// Detection is deliberately clock-agnostic: a ticker set to fire every
+// rxWatchdogTickInterval that instead fires suspendGapThreshold late means
+// this process was not running. Whether that was a laptop sleeping, a
+// paused VM, or brutal CPU starvation does not matter — in every case the
+// transport state predating the gap is untrustworthy and re-establishing it
+// is both correct and cheap.
+//
+// Two actions, neither of which restarts anything:
+//
+//  1. Re-punch and re-register: RegisterWithBeacon refreshes the NAT
+//     mapping (its discover reply doubles as an inbound probe) and the
+//     registry gets a fresh conn, since the pooled one did not survive the
+//     suspend and has no liveness ping of its own.
+//  2. Reset the wedge baseline. The pre-suspend counters describe a
+//     different epoch: PktsRecv/PktsSent are frozen at their pre-sleep
+//     values while lastProgress is hours old, so the very first tick after
+//     resume would otherwise read as a multi-hour rx silence and burn soft
+//     attempts on a wedge that had not been given a chance to recover yet.
+func (d *Daemon) rxWatchdogResume(st *rxWatchdogState, now time.Time, gap time.Duration) {
+	defer recoverLayer("L4", "rxWatchdogResume", d.bus, nil)
+
+	slog.Warn("host resumed from suspend — re-establishing transport",
+		"gap", gap.Truncate(time.Second).String(),
+		"tick_interval", rxWatchdogTickInterval.String())
+	d.publishEvent("tunnel.host_resumed", map[string]any{
+		"gap_seconds": int64(gap.Seconds()),
+	})
+
+	d.tunnels.RegisterWithBeacon()
+	if d.reg() != nil {
+		// The pooled registry conn cannot have survived the suspend, and it
+		// has no half-open detection of its own, so force a fresh one rather
+		// than waiting for a request to hang on the dead socket.
+		if err := d.forceReconnectRegistry(); err != nil {
+			slog.Warn("registry reconnect after resume failed", "error", err)
+		} else {
+			d.reRegister()
+		}
+	}
+
+	// Fresh epoch: re-baseline so the first post-resume tick measures
+	// recovery, not the suspend.
+	st.recvSeen = atomic.LoadUint64(&d.tunnels.PktsRecv)
+	st.sentAtProgress = atomic.LoadUint64(&d.tunnels.PktsSent)
+	st.lastProgress = now
+	st.softAttempts = 0
+	st.suspendSeen = true
+	d.consecutiveDialTimeouts.Store(0)
+}
+
 // rxWatchdogTick runs one watchdog iteration. Extracted for testability —
 // production drives it from rxWatchdogLoop; tests drive it directly.
 //
@@ -263,9 +354,14 @@ func (d *Daemon) rxWatchdogTick(st *rxWatchdogState, now time.Time) (action rxWa
 	}
 	uptime := now.Sub(d.startTime)
 	switch {
-	case st.recvSeen == 0:
+	case st.recvSeen == 0 && !st.suspendSeen:
 		// Never received a tunnel packet this process — a restart would
 		// reproduce the same state (boot loop). Keep soft-recovering.
+		//
+		// Skipped once the host has suspended: after a resume, "no inbound
+		// yet this process" is a symptom of the gap, not evidence that
+		// inbound can never work here, and a restart is precisely what
+		// clears it.
 		slog.Warn("inbound path silent and never progressed — withholding restart, will keep soft-recovering",
 			"silent_for", silence.Truncate(time.Second).String())
 	case registryAge < 0 || registryAge > rxWedgeRegistryFresh:

pkg/daemon/zz_rx_watchdog_suspend_test.go

@@ -0,0 +1,120 @@
+// SPDX-License-Identifier: AGPL-3.0-or-later
+
+package daemon
+
+import (
+	"sync/atomic"
+	"testing"
+	"time"
+)
+
+// TestSuspendUnlocksNeverProgressedGuard reproduces the field failure: a
+// laptop resumes from sleep, inbound is dead, and the watchdog refuses to
+// escalate forever because PktsRecv never advanced this process.
+//
+// On one laptop's daemon.log, 301 of 344 withheld restarts were this guard
+// ("never progressed"); only 4 were the registry check. The operator had to
+// restart the daemon by hand every time.
+//
+// The guard is correct for a host whose inbound never worked — restarting
+// would boot-loop. It is wrong after a host suspend, where the transport
+// worked before the gap and a restart is exactly what recovers it.
+func TestSuspendUnlocksNeverProgressedGuard(t *testing.T) {
+	// Must not be parallel: this stubs the global rxWatchdogExit, and the
+	// escalation path below really would call os.Exit(86) otherwise.
+	exitCode := swapExitForTest(t)
+	now := time.Now()
+
+	// No inbound has ever been delivered this process, but we are
+	// transmitting hard — the post-resume signature.
+	newWedged := func() (*Daemon, *rxWatchdogState) {
+		d := newRxWatchdogTestDaemon(t)
+		atomic.StoreUint64(&d.tunnels.PktsRecv, 0)
+		atomic.StoreUint64(&d.tunnels.PktsSent, 5000)
+		d.lastRegistryOKNano.Store(now.UnixNano())
+		d.startTime = now.Add(-2 * rxWedgeMinUptime)
+
+		st := &rxWatchdogState{
+			lastProgress:   now.Add(-10 * rxSilenceThreshold),
+			recvSeen:       0,
+			sentAtProgress: 0,
+		}
+		return d, st
+	}
+
+	// Without a suspend the guard must still hold — a genuinely broken
+	// host must not boot-loop.
+	d, st := newWedged()
+	var action rxWatchdogAction
+	for i := 0; i < rxWatchdogSoftMax+1; i++ {
+		action = d.rxWatchdogTick(st, now)
+	}
+	if action == rxActionExit {
+		t.Fatal("exited despite never having received inbound and no suspend — " +
+			"this is the boot-loop the guard exists to prevent")
+	}
+
+	// After a suspend, the same state must escalate to the restart.
+	d, st = newWedged()
+	st.suspendSeen = true
+	for i := 0; i < rxWatchdogSoftMax+1; i++ {
+		action = d.rxWatchdogTick(st, now)
+	}
+	if action != rxActionExit {
+		t.Fatalf("post-suspend wedge did not escalate to restart: got %q — "+
+			"this is the bug that forced a manual `pilotctl daemon restart` after every lid-close", action)
+	}
+	if *exitCode != rxWedgeExitCode {
+		t.Fatalf("exit code = %d, want %d (the value launchd/systemd respawn on)", *exitCode, rxWedgeExitCode)
+	}
+}
+
+// TestResumeReBaselinesAndMarksSuspend pins what the resume handler does:
+// it re-baselines the wedge counters (the pre-suspend epoch is meaningless)
+// and records that a suspend happened so the guard above unlocks.
+func TestResumeReBaselinesAndMarksSuspend(t *testing.T) {
+	d := newRxWatchdogTestDaemon(t)
+	atomic.StoreUint64(&d.tunnels.PktsRecv, 4242)
+	atomic.StoreUint64(&d.tunnels.PktsSent, 9999)
+
+	now := time.Now()
+	st := &rxWatchdogState{
+		lastProgress:   now.Add(-8 * time.Hour), // slept overnight
+		recvSeen:       10,
+		sentAtProgress: 20,
+		softAttempts:   2,
+	}
+
+	d.rxWatchdogResume(st, now, 8*time.Hour)
+
+	if !st.suspendSeen {
+		t.Error("suspendSeen not set — the never-progressed guard stays locked")
+	}
+	if st.softAttempts != 0 {
+		t.Errorf("softAttempts = %d, want 0: the pre-suspend attempts describe a different epoch", st.softAttempts)
+	}
+	if !st.lastProgress.Equal(now) {
+		t.Error("lastProgress not re-baselined — the first post-resume tick would read as an 8h rx silence")
+	}
+	if st.recvSeen != 4242 || st.sentAtProgress != 9999 {
+		t.Errorf("counters not re-baselined: recvSeen=%d sentAtProgress=%d", st.recvSeen, st.sentAtProgress)
+	}
+}
+
+// TestSuspendGapThresholdIgnoresOrdinaryJitter guards the detector against
+// firing on a merely-late tick. Recovery is cheap but not free — it
+// re-punches NAT and forces a fresh registry connection.
+func TestSuspendGapThresholdIgnoresOrdinaryJitter(t *testing.T) {
+	if suspendGapThreshold <= rxWatchdogTickInterval {
+		t.Fatal("threshold must exceed the tick interval or every tick is a suspend")
+	}
+	// A tick arriving at 2x the interval is slow, not a suspend.
+	if 2*rxWatchdogTickInterval >= suspendGapThreshold {
+		t.Errorf("threshold %v too tight: a merely slow tick (2x interval) would be read as a host suspend",
+			suspendGapThreshold)
+	}
+	// A lid-close is minutes at least; the threshold must be well under it.
+	if suspendGapThreshold > 5*time.Minute {
+		t.Errorf("threshold %v too loose: short suspends would go undetected", suspendGapThreshold)
+	}
+}