Skip to content

Commit 3846f6f

Browse files
TeoSlayerteovlclaude
authored
daemon: inbound-path watchdog — auto-recover the long-uptime NAT wedge (#369)
* daemon: add inbound-path watchdog — auto-recover the long-uptime NAT wedge A daemon could run for days transmitting into a stale NAT/relay mapping while receiving nothing (2026-07-13 incident: 43.5 MB sent vs 102 KB received over 2d19h, every send-message failing with "cannot connect (data exchange port 1001)"). The registry heartbeat is TCP and kept succeeding, so trustRepublishLoop never noticed and only a manual restart cleared it. The new watchdog (pkg/daemon/rxwatchdog.go) samples PktsRecv/PktsSent every 30s. On 3 min of delivered-packet silence with active transmit it soft-recovers: RegisterWithBeacon (the discover reply doubles as an active inbound probe) plus registry reRegister. If the wedge survives 3 soft attempts it exits with code 86 so launchd (KeepAlive SuccessfulExit=false) / systemd (Restart=always) respawn the daemon with a fresh transport — the remedy that demonstrably clears the wedge. Flap guards on the hard exit: never fires when the registry is also unreachable (machine offline — restart fixes nothing), when inbound never progressed this process (would boot-loop), or within 30 min of start. Emits tunnel.rx_silence / tunnel.rx_recovered / tunnel.rx_wedged_exit. Disable with -no-rx-watchdog. Supporting changes: - tunnel.go: LastRecvNano stamped on every raw datagram + LastRecvTime() accessor, so logs separate dead-socket from dead-session-layer wedges. - daemon.go: lastRegistryOKNano stamped on registration/heartbeat/ re-registration successes; startTime now set at the top of Start() so watchdog goroutine reads never race the historical late assignment. - pilotctl daemon start: launchd readiness wait 10s -> 30s — app-store apps spawn before IPC comes up, and the old timeout reported a false failure for boots that succeed moments later. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> * go.mod: bump go directive 1.25.11 -> 1.25.12 (GO-2026-5856) govulncheck flags GO-2026-5856 (crypto/tls Encrypted Client Hello privacy leak), fixed in the standard library at go1.25.12. CI installs the toolchain via go-version-file: go.mod, so bumping the go directive pulls in the fixed stdlib and clears the vuln repo-wide. Build verified under go1.25.12. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> * rxwatchdog: suppress gosec G404 on startup jitter (scheduling, not crypto) Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> --------- Co-authored-by: Teodor Calin <teodor@vulturelabs.io> Co-authored-by: Claude Fable 5 <noreply@anthropic.com>
1 parent 1eb714c commit 3846f6f

8 files changed

Lines changed: 496 additions & 5 deletions

File tree

CHANGELOG.md

Lines changed: 21 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -12,6 +12,21 @@ Detailed per-release notes are on the
1212
Reliable P2P data transfer across NAT. Tag intentionally held for review.
1313

1414
### Added
15+
- **Inbound-path watchdog — the long-uptime NAT wedge now auto-recovers.**
16+
A daemon could run for days transmitting into a stale NAT/relay mapping
17+
while receiving nothing (2026-07-13 incident: 43.5 MB sent vs 102 KB
18+
received over 2d19h, every `send-message` failing with "cannot connect
19+
(data exchange port 1001)") — the registry heartbeat is TCP and kept
20+
succeeding, so nothing noticed until a manual restart. The daemon now
21+
watches for delivered-packet silence while transmit stays active, first
22+
soft-recovers (beacon re-registration — whose discover reply doubles as
23+
an active inbound probe — plus registry re-registration), and if the
24+
wedge persists on a supervised daemon, exits with code 86 so
25+
launchd/systemd respawns it with a fresh transport. Guarded against
26+
flapping: never exits when the registry is also unreachable (machine
27+
offline), when inbound never worked this process, or within 30 min of
28+
start. Emits `tunnel.rx_silence` / `tunnel.rx_recovered` /
29+
`tunnel.rx_wedged_exit` webhook events. Disable with `-no-rx-watchdog`.
1530
- **Chunked, ACK'd, resumable file transfer (`TypeFileStream`).** `pilotctl
1631
send-file` now streams files in 48 KiB chunks with per-chunk ACKs, an
1732
end-to-end SHA-256 integrity check, and automatic resume from the last
@@ -39,6 +54,12 @@ Reliable P2P data transfer across NAT. Tag intentionally held for review.
3954
`--motd-feed-url` / `$PILOT_MOTD_URL` as before. (motd)
4055

4156
### Fixed
57+
- **`pilotctl daemon start` no longer reports a false failure on slow boots.**
58+
The launchd path waited only 10 s for the IPC socket; a daemon with
59+
installed app-store apps spawns them before IPC comes up and can take
60+
longer, producing "socket did not become ready within 10s" for a start
61+
that succeeds moments later. The wait is now 30 s and the timeout message
62+
says launchd is still supervising the boot.
4263
- **NAT traversal now actually establishes (and holds) a direct path.** The
4364
relay→direct upgrade sent a one-way probe that a stateful NAT/firewall
4465
always dropped, so peers stayed on the beacon relay indefinitely. The

cmd/daemon/main.go

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -94,6 +94,7 @@ func main() {
9494
networks := flag.String("networks", "", "comma-separated network IDs to auto-join at startup")
9595
trustAutoApprove := flag.Bool("trust-auto-approve", false, "automatically approve all incoming trust handshakes")
9696
beaconRTTProbe := flag.Bool("beacon-rtt-probe", false, "probe beacon RTT before selection; override hash pick when >2× slower than best (ablation test, default off)")
97+
noRxWatchdog := flag.Bool("no-rx-watchdog", false, "disable the inbound-path watchdog that soft-recovers (beacon+registry re-registration) and, on a persistent wedge, exits non-zero for supervisor respawn")
9798
transportMode := flag.String("transport", "udp", "tunnel transport: 'udp' (default) or 'compat' (WSS to beacon, opt-in, for UDP-blocked environments)")
9899
compatBeacon := flag.String("compat-beacon", "wss://beacon.pilotprotocol.network/v1/compat", "beacon WSS URL for -transport=compat")
99100
tlsTrust := flag.String("tls-trust", "system", "TLS trust store for -transport=compat: 'system' (OS trust store; current default while compat mode uses Let's Encrypt certs on beacon.pilotprotocol.network) or 'pinned' (Pilot CA root embedded in the daemon binary; will become the default in a future release once production root ships)")
@@ -248,6 +249,7 @@ func main() {
248249
Version: version,
249250
TrustAutoApprove: *trustAutoApprove,
250251
BeaconRTTProbe: *beaconRTTProbe,
252+
DisableRxWatchdog: *noRxWatchdog,
251253
TransportMode: *transportMode,
252254
CompatBeaconURL: *compatBeacon,
253255
CompatTLSTrust: *tlsTrust,

cmd/pilotctl/main.go

Lines changed: 9 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -2791,8 +2791,12 @@ func cmdDaemonStart(args []string) {
27912791
if err := exec.Command("launchctl", "bootstrap", fmt.Sprintf("gui/%d", os.Getuid()), plist).Run(); err != nil {
27922792
fatalCode("internal", "launchctl bootstrap: %v", err)
27932793
}
2794-
// Poll socket until daemon is responsive.
2795-
waitDeadline := time.Now().Add(10 * time.Second)
2794+
// Poll socket until daemon is responsive. 30s, not 10s: a daemon
2795+
// with installed app-store apps spawns them before IPC comes up,
2796+
// which can push readiness past 10s on a loaded machine — and a
2797+
// premature "not ready" here reads as a failed start even though
2798+
// launchd keeps supervising and the daemon finishes booting fine.
2799+
waitDeadline := time.Now().Add(30 * time.Second)
27962800
for time.Now().Before(waitDeadline) {
27972801
if d, err := driver.Connect(getSocket()); err == nil {
27982802
if _, err := d.Info(); err == nil {
@@ -2808,7 +2812,9 @@ func cmdDaemonStart(args []string) {
28082812
}
28092813
time.Sleep(200 * time.Millisecond)
28102814
}
2811-
fatalCode("timeout", "launchd loaded the agent but the socket did not become ready within 10s")
2815+
fatalHint("timeout",
2816+
"launchd is still supervising it — check `pilotctl daemon status` and the daemon log",
2817+
"launchd loaded the agent but the socket did not become ready within 30s")
28122818
}
28132819

28142820
// Check if already running

go.mod

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,6 @@
11
module github.com/pilot-protocol/pilotprotocol
22

3-
go 1.25.11
3+
go 1.25.12
44

55
require (
66
github.com/coder/websocket v1.8.15

pkg/daemon/daemon.go

Lines changed: 32 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -136,6 +136,17 @@ type Config struct {
136136
// Feature flags — ablation testing. All default false (current behavior).
137137
BeaconRTTProbe bool // probe beacon RTT; override hash pick when >2× slower than best
138138

139+
// DisableRxWatchdog turns off the inbound-path watchdog (rxwatchdog.go).
140+
// The watchdog detects the long-uptime wedge where the daemon keeps
141+
// transmitting but the inbound UDP path has silently died (stale NAT /
142+
// relay mapping — 2026-07-13 incident: 43.5 MB sent vs 102 KB received
143+
// over 2d19h, every send-message failing with "cannot connect"). It
144+
// first soft-recovers (beacon + registry re-registration) and, if the
145+
// wedge persists on a supervised daemon, exits non-zero so
146+
// launchd/systemd respawns with a clean transport. Default false
147+
// (watchdog on) — the wedge otherwise requires a manual restart.
148+
DisableRxWatchdog bool
149+
139150
// Telemetry consent gate. When set to the telemetry endpoint URL,
140151
// the daemon initialises a telemetry client that emits signed events
141152
// (install, usage, view, review). When empty (default), the client
@@ -332,6 +343,13 @@ type Daemon struct {
332343
netSubMu sync.Mutex
333344
netSubStop func()
334345

346+
// lastRegistryOKNano is the unix-nano time of the last successful
347+
// registry interaction (initial registration, heartbeat, or
348+
// re-registration). The rx watchdog uses it to distinguish "data
349+
// plane wedged, control plane fine" (restart helps — the incident
350+
// signature) from "whole network unreachable" (restart just loops).
351+
lastRegistryOKNano atomic.Int64
352+
335353
startTime time.Time
336354
stopCh chan struct{} // closed on Stop() to signal goroutines
337355
beaconSelection *beaconSelectionState // multi-beacon discovery state
@@ -653,6 +671,12 @@ func (d *Daemon) SetRekeyWhitelist(nodeIDs []uint32) {
653671
}
654672

655673
func (d *Daemon) Start() error {
674+
// Stamp startTime before any background goroutine launches — the rx
675+
// watchdog reads it from its own goroutine for the min-uptime guard,
676+
// and the historical assignment at the bottom of Start left a window
677+
// where a loop could read the zero value.
678+
d.startTime = time.Now()
679+
656680
// Warm the hostname cache from disk before the IPC server comes up,
657681
// so the first send-message after restart hits the cache instead of
658682
// pounding regConn for a fresh resolve_hostname.
@@ -1056,6 +1080,7 @@ func (d *Daemon) Start() error {
10561080
d.addrMu.Unlock()
10571081

10581082
slog.Info("daemon registered", "node_id", d.nodeID, "addr", d.addr, "endpoint", registrationAddr)
1083+
d.lastRegistryOKNano.Store(time.Now().UnixNano())
10591084

10601085
// T4.1: webhook is now a bus subscriber owned by plugins/webhook.
10611086
// cmd/daemon (composition root) constructs the plugin and starts
@@ -1183,6 +1208,11 @@ func (d *Daemon) Start() error {
11831208
d.bgWG.Add(1)
11841209
go func() { defer d.bgWG.Done(); d.observabilityHeartbeatLoop() }()
11851210

1211+
// 8b. Start inbound-path watchdog (L4). Detects the "transmitting into
1212+
// a dead NAT mapping" wedge and recovers — see rxwatchdog.go.
1213+
d.bgWG.Add(1)
1214+
go func() { defer d.bgWG.Done(); d.rxWatchdogLoop() }()
1215+
11861216
// 9. Start idle connection sweeper
11871217
d.bgWG.Add(1)
11881218
go func() { defer d.bgWG.Done(); d.idleSweepLoop() }()
@@ -1260,7 +1290,6 @@ func (d *Daemon) Start() error {
12601290
// runtime.StartPlugins(ctx) AFTER this Start returns. This
12611291
// inversion is T7.1: pkg/daemon no longer imports pkg/coreapi.
12621292

1263-
d.startTime = time.Now()
12641293
slog.Info("daemon running", "node_id", d.nodeID, "addr", d.addr)
12651294
return nil
12661295
}
@@ -4950,6 +4979,7 @@ func (d *Daemon) trustRepublishLoop() {
49504979
}
49514980
consecutiveFailures = 0
49524981
reregBackoff = 100 * time.Millisecond
4982+
d.lastRegistryOKNano.Store(time.Now().UnixNano())
49534983
}
49544984
}
49554985
}
@@ -5102,6 +5132,7 @@ func (d *Daemon) reRegister() {
51025132
nodeID := d.nodeID
51035133
slog.Info("re-registered", "node_id", nodeID, "addr", d.addr)
51045134
d.addrMu.Unlock()
5135+
d.lastRegistryOKNano.Store(time.Now().UnixNano())
51055136
d.publishEvent("node.reregistered", map[string]interface{}{
51065137
"address": d.addr.String(),
51075138
})

0 commit comments

Comments
 (0)