daemon: cooldown the dial-driven auto-handshake spawn (#216)

DialConnection unconditionally spawned `go HandshakeSendRequest(peer, "")`
on every call to a peer in the trustedagents allowlist that wasn't
yet trusted. The per-peer in-flight dedup collapsed CONCURRENT callers
to one underlying SendRequest, but did NOT collapse SEQUENTIAL ones:
once sendMessage returned fast (ErrEphemeralExhausted, or the
registry-relay fallback), the slot was released within microseconds
and the next dial re-fired the goroutine — re-emitting "direct
handshake failed" and re-allocating an ephemeral port.

In steady state against an unreachable trusted-agent (blockchain-ticker,
node 19418, 2026-06-06) this produced ~4000 log lines per second.
daemon.log grew to 1 GB in under four hours and the port pool
saturated; pilotctl info/peers/handshake all wedged because the IPC
server couldn't get a port through the bitmap.

Add shouldAutoHandshake: a per-peer time-keyed gate (autoHandshakeCooldown
= 30 s) checked BEFORE the goroutine spawn. Concurrent racers atomic-CAS
for the slot; sequential callers within the cooldown short-circuit
without ever reaching HandshakeSendRequest. Explicit `pilotctl handshake`
IPC calls bypass the gate — user intent is never throttled.

Regression-pinned by six TestShouldAutoHandshake* cases, including a
50k-call tight loop asserting exactly one spawn.

Co-authored-by: Teodor Calin <teodor@vulturelabs.io>

Author: TeoSlayer

CHANGELOG.md

@@ -7,6 +7,41 @@ project uses [Semantic Versioning](https://semver.org/).
 Detailed per-release notes are on the
 [GitHub Releases page](https://github.com/TeoSlayer/pilotprotocol/releases).
 
+## [Unreleased]
+
+### Fixed
+- **Auto-handshake dial-storm against unreachable trusted agents no longer
+  saturates the ephemeral-port pool.** When `DialConnection` targeted a
+  peer in the `trustedagents` allowlist that wasn't yet trusted, it
+  unconditionally spawned `go HandshakeSendRequest(peer, "")` on every
+  call. The existing per-peer in-flight dedup collapsed CONCURRENT
+  callers to a single underlying `SendRequest`, but did NOT collapse
+  SEQUENTIAL ones: when `sendMessage` returned fast (e.g. hit
+  `ErrEphemeralExhausted` in microseconds, or the registry-relay
+  fallback completed), the in-flight slot was released immediately and
+  the next dial re-fired the goroutine — re-entering `SendRequest`,
+  re-emitting `"direct handshake failed, relaying via registry"`, and
+  re-allocating an ephemeral port.
+
+  In steady state against a reachable-but-key-exchange-stuck peer
+  (`blockchain-ticker`, node 19418, on 2026-06-06) this produced
+  ~4000 log lines per second — 1 GB of `daemon.log` written in under
+  four hours — while every outbound dial to that peer and every
+  concurrent tenant of the port pool failed with `"ephemeral ports
+  exhausted"`. `pilotctl info`, `pilotctl peers`, and new specialist
+  handshakes all wedged because the IPC server couldn't get a port
+  through the saturated bitmap.
+
+  Fix: `Daemon.shouldAutoHandshake` adds a per-peer time-keyed gate
+  (`autoHandshakeCooldown` = 30 s) that runs BEFORE the goroutine
+  spawn in `DialConnection`. Concurrent racers atomic-CAS for the
+  slot; sequential callers within the cooldown window short-circuit
+  silently and never reach `HandshakeSendRequest`. Explicit
+  `pilotctl handshake <peer>` IPC calls bypass the gate so user
+  intent is never throttled. Regression-pinned by
+  `TestShouldAutoHandshake*` (six cases including a 50k-call tight
+  loop that asserts exactly one spawn).
+
 ## [1.10.5] - 2026-05-20
 
 ### Fixed

pkg/daemon/daemon.go

@@ -270,6 +270,28 @@ type Daemon struct {
 	// dial regardless of caller count.
 	handshakeInFlight sync.Map
 
+	// autoHandshakeLastAttempt records the last time DialConnection's
+	// inline trusted-agents auto-handshake (daemon.go ~3139) fired for
+	// a peer (nodeID → time.Time). Used by shouldAutoHandshake to
+	// throttle the dial-driven fanout: handshakeInFlight only collapses
+	// CONCURRENT callers, not SEQUENTIAL ones — when SendRequest
+	// returns fast (e.g. sendMessage hits ErrEphemeralExhausted in
+	// microseconds, or the registry-relay fallback completes), the
+	// in-flight slot is released immediately and the next DialConnection
+	// caller re-fires the goroutine, re-enters SendRequest, and emits
+	// another "direct handshake failed" log line. Without a cooldown,
+	// this produced a 4k-log-line-per-second storm against
+	// blockchain-ticker (node 19418) on 2026-06-06 — daemon log grew
+	// to 1 GB in under four hours while every outbound dial to that
+	// peer (and any concurrent tenant of the port pool) failed with
+	// "ephemeral ports exhausted".
+	//
+	// Distinct from handshakeInFlight (concurrent-burst dedup): this is
+	// a separate time-keyed gate that runs only on the DialConnection
+	// auto-spawn path, so explicit user-initiated `pilotctl handshake`
+	// IPC calls are NOT throttled.
+	autoHandshakeLastAttempt sync.Map
+
 	// network.* bus subscriber for daemon-internal reactions (managed
 	// engines + member-tag cache). Wired by subscribeNetworkInternalToBus
 	// during Start; torn down before tunnels in doStop. (T4.3.)
@@ -1869,6 +1891,48 @@ func (d *Daemon) HandshakeRevokeTrust(nodeID uint32) error {
 // pilotctl users get a clean signal rather than a generic error.
 var ErrHandshakeInFlight = errors.New("handshake already in flight to this peer")
 
+// autoHandshakeCooldown is the per-peer minimum gap between
+// DialConnection-driven auto-handshake spawns. Sized to match the dial
+// budget (~25-78s of direct-retry + relay) so a peer that's unreachable
+// can't drive log/dial fanout faster than the dial itself takes. The
+// next caller still gets an auto-handshake — just not 4000 of them per
+// second from the same hot dial path.
+const autoHandshakeCooldown = 30 * time.Second
+
+// shouldAutoHandshake reports whether DialConnection's inline
+// trusted-agents auto-handshake should fire for peer. Returns true the
+// first time it sees the peer and after autoHandshakeCooldown has
+// elapsed since the last spawn. Records the spawn time atomically so
+// concurrent racers see one winner; subsequent callers within the
+// cooldown window observe a recent timestamp and return false without
+// spawning a goroutine.
+//
+// Gates only the dial-driven auto-spawn path: explicit
+// `pilotctl handshake <peer>` IPC calls hit HandshakeSendRequest
+// directly and are unaffected (so a user explicitly retrying is never
+// silently dropped).
+func (d *Daemon) shouldAutoHandshake(peer uint32) bool {
+	now := time.Now()
+	prev, loaded := d.autoHandshakeLastAttempt.LoadOrStore(peer, now)
+	if !loaded {
+		return true
+	}
+	prevTime, ok := prev.(time.Time)
+	if !ok {
+		// Defensive — value type mismatch should be impossible, but if
+		// it happens, overwrite and proceed rather than wedge.
+		d.autoHandshakeLastAttempt.Store(peer, now)
+		return true
+	}
+	if now.Sub(prevTime) < autoHandshakeCooldown {
+		return false
+	}
+	// Cooldown expired — race to claim the slot. CompareAndSwap means at
+	// most one of N concurrent racers wins; the rest skip this round and
+	// will try again on the next dial after cooldown.
+	return d.autoHandshakeLastAttempt.CompareAndSwap(peer, prev, now)
+}
+
 // HandshakeSendRequest issues an outbound trust handshake to peerNodeID
 // via the registered handshake plugin, deduped per-peer.
 //
@@ -3194,10 +3258,26 @@ func (d *Daemon) dialConnectionLocked(ctx context.Context, dstAddr protocol.Addr
 			// peer, all from the recursive go-fired chain. The wrapper's
 			// LoadOrStore caps it at one in-flight call per peer.
 			//
+			// The in-flight dedup catches CONCURRENT racers. It does NOT
+			// catch the SEQUENTIAL retry storm that emerges when the
+			// underlying SendRequest returns fast (e.g. sendMessage hits
+			// ErrEphemeralExhausted): the slot is released within
+			// microseconds and the next DialConnection re-fires the
+			// goroutine immediately, producing 4k+ "direct handshake
+			// failed" log lines per second (1 GB of daemon log in <4 h
+			// observed against blockchain-ticker, node 19418, on
+			// 2026-06-06). shouldAutoHandshake adds a per-peer time
+			// cooldown so the auto-spawn fires at most once per
+			// autoHandshakeCooldown, regardless of caller volume.
+			// Explicit `pilotctl handshake` IPC calls still bypass this
+			// gate.
+			//
 			// Returns are intentionally discarded — the goroutine is best
 			// effort, just like before. ErrHandshakeInFlight short-circuit
 			// is the dedup hit, which is the success case.
-			go func() { _ = d.HandshakeSendRequest(dstAddr.Node, "") }()
+			if d.shouldAutoHandshake(dstAddr.Node) {
+				go func() { _ = d.HandshakeSendRequest(dstAddr.Node, "") }()
+			}
 		}
 	}
 

pkg/daemon/zz_auto_handshake_cooldown_test.go

@@ -0,0 +1,156 @@
+// SPDX-License-Identifier: AGPL-3.0-or-later
+
+package daemon
+
+// Pins the per-peer auto-handshake cooldown that gates the inline
+// DialConnection spawn of HandshakeSendRequest for peers in the
+// trustedagents allowlist.
+//
+// Motivation: handshakeInFlight collapses CONCURRENT auto-handshake
+// callers to a single underlying SendRequest. It does not collapse
+// SEQUENTIAL callers — when SendRequest returns fast (e.g. sendMessage
+// hits ErrEphemeralExhausted in microseconds, or the registry-relay
+// fallback completes), the in-flight slot is released immediately and
+// the next DialConnection caller re-fires the goroutine, re-enters
+// SendRequest, and emits another "direct handshake failed" log line.
+// Without a cooldown this produces a 4k-log-line-per-second storm
+// against an unreachable trusted-agent (observed: 1 GB of daemon log
+// in under 4 h against blockchain-ticker / node 19418, 2026-06-06).
+//
+// shouldAutoHandshake records the spawn time per peer and rejects
+// subsequent calls within autoHandshakeCooldown. These tests verify
+// that contract end-to-end without spinning up the full plugin stack.
+
+import (
+	"sync"
+	"sync/atomic"
+	"testing"
+	"time"
+)
+
+// TestShouldAutoHandshakeFirstCallFires verifies the first call for an
+// unseen peer always returns true (no cooldown to wait through).
+func TestShouldAutoHandshakeFirstCallFires(t *testing.T) {
+	t.Parallel()
+	d := &Daemon{}
+	if !d.shouldAutoHandshake(7777) {
+		t.Fatalf("first call for an unseen peer must return true")
+	}
+}
+
+// TestShouldAutoHandshakeRepeatWithinCooldownSuppressed verifies that
+// subsequent calls within autoHandshakeCooldown return false — the
+// regression that motivated the gate (4k-per-sec dial-driven re-entry).
+func TestShouldAutoHandshakeRepeatWithinCooldownSuppressed(t *testing.T) {
+	t.Parallel()
+	d := &Daemon{}
+	const peer = uint32(8888)
+
+	if !d.shouldAutoHandshake(peer) {
+		t.Fatalf("first call must fire")
+	}
+	for i := 0; i < 1000; i++ {
+		if d.shouldAutoHandshake(peer) {
+			t.Fatalf("repeat call %d within cooldown returned true; cooldown gate failed", i)
+		}
+	}
+}
+
+// TestShouldAutoHandshakeDifferentPeersIndependent verifies the cooldown
+// is keyed strictly by peer ID — a hot dial path against peer A must
+// not silence auto-handshakes to unrelated peer B.
+func TestShouldAutoHandshakeDifferentPeersIndependent(t *testing.T) {
+	t.Parallel()
+	d := &Daemon{}
+
+	if !d.shouldAutoHandshake(1001) {
+		t.Fatalf("peer 1001 first call must fire")
+	}
+	if d.shouldAutoHandshake(1001) {
+		t.Fatalf("peer 1001 second call within cooldown must skip")
+	}
+	if !d.shouldAutoHandshake(1002) {
+		t.Fatalf("peer 1002 first call must fire (independent of 1001)")
+	}
+	if !d.shouldAutoHandshake(1003) {
+		t.Fatalf("peer 1003 first call must fire (independent of 1001/1002)")
+	}
+}
+
+// TestShouldAutoHandshakeConcurrentRacersOneWinner verifies the
+// CompareAndSwap path: N goroutines racing to fire for the same peer
+// must yield exactly one true result, the rest false.
+func TestShouldAutoHandshakeConcurrentRacersOneWinner(t *testing.T) {
+	t.Parallel()
+	d := &Daemon{}
+	const peer = uint32(2024)
+	const N = 64
+
+	var trueCount atomic.Int32
+	var wg sync.WaitGroup
+	start := make(chan struct{})
+
+	wg.Add(N)
+	for i := 0; i < N; i++ {
+		go func() {
+			defer wg.Done()
+			<-start
+			if d.shouldAutoHandshake(peer) {
+				trueCount.Add(1)
+			}
+		}()
+	}
+	close(start)
+	wg.Wait()
+
+	if got := trueCount.Load(); got != 1 {
+		t.Fatalf("%d goroutines saw shouldAutoHandshake=true, want exactly 1 (CompareAndSwap should pick one winner)", got)
+	}
+}
+
+// TestShouldAutoHandshakeFiresAgainAfterCooldown verifies the gate
+// releases when the cooldown elapses — a peer that's persistently
+// unreachable still gets a fresh attempt periodically (so trust can
+// converge once the peer comes back).
+//
+// Rather than sleep for autoHandshakeCooldown (30s), we directly seed
+// the map with an old timestamp to simulate cooldown expiry. This
+// pins the behaviour without making the test sleep through the real
+// cooldown.
+func TestShouldAutoHandshakeFiresAgainAfterCooldown(t *testing.T) {
+	t.Parallel()
+	d := &Daemon{}
+	const peer = uint32(3030)
+
+	// Seed an attempt that's well past the cooldown window.
+	d.autoHandshakeLastAttempt.Store(peer, time.Now().Add(-2*autoHandshakeCooldown))
+
+	if !d.shouldAutoHandshake(peer) {
+		t.Fatalf("call after cooldown elapsed must fire")
+	}
+	if d.shouldAutoHandshake(peer) {
+		t.Fatalf("immediately-following call within new cooldown must be suppressed")
+	}
+}
+
+// TestShouldAutoHandshakeStormSuppression simulates the regression
+// directly: a dial-driven hot path slams shouldAutoHandshake N times
+// at a single peer in a tight loop, and we assert the gate caps the
+// fanout at exactly 1 (so the goroutine spawn rate is bounded, not
+// the 4000/sec storm observed in the wild).
+func TestShouldAutoHandshakeStormSuppression(t *testing.T) {
+	t.Parallel()
+	d := &Daemon{}
+	const peer = uint32(19418) // the real-world repro peer (blockchain-ticker)
+	const N = 50_000
+
+	fires := 0
+	for i := 0; i < N; i++ {
+		if d.shouldAutoHandshake(peer) {
+			fires++
+		}
+	}
+	if fires != 1 {
+		t.Fatalf("auto-handshake fired %d times in a %d-call tight loop, want exactly 1 — storm suppression failed", fires, N)
+	}
+}