From e23099303378cb06661bcc0beac7785cdbaf9683 Mon Sep 17 00:00:00 2001 From: Teo Calin Date: Fri, 2 Oct 2026 00:30:36 +0300 Subject: [PATCH] daemon: keep blackholed peers on the relay; stop the next packet overwriting a cached peer key Two bugs found while tracing why a node kept losing its path to one peer (list-agents) on 2026-10-01. Relay flag cleared on unpin. tryDirectUpgrade runs every RelayProbeInterval (15 s) for each relay peer. To let a working direct path win it must unpin a peer the blackhole heuristic pinned, and it called SetRelayPeerPinned(id, false), which clears the relay flag as well as the pin. Every blackholed peer was therefore back on its dead direct path within 15 s and stayed there until three more silent sends flipped it again: about 75 s of every 90 s spent sending to an address that never answers. A new routing.UnpinRelayPeer removes only the pin; ClearRelayOnDirect still moves the peer back after DirectClearsRequired direct packets. Cached peer key aliased the receive buffer. HandleAuthFrame sliced the peer's Ed25519 key out of the frame it was handed and cached that slice. The frame is the socket's single reused read buffer, so the next packet overwrote the cached key. The next PILA from the peer mismatched the cache and triggered a registry lookup on the UDP read loop ("auth key exchange: peer pubkey updated from registry"). The key is now copied when parsed, and SetPeerPubKey copies what it is given. Co-Authored-By: Claude Opus 5.5 --- CHANGELOG.md | 19 +++ pkg/daemon/daemon.go | 10 +- pkg/daemon/keyexchange/handle.go | 6 +- pkg/daemon/keyexchange/keyexchange.go | 6 +- .../zz_peer_key_buffer_alias_test.go | 77 +++++++++++ pkg/daemon/routing/relay.go | 12 ++ pkg/daemon/tunnel.go | 6 + .../zz_direct_upgrade_keeps_relay_test.go | 130 ++++++++++++++++++ 8 files changed, 263 insertions(+), 3 deletions(-) create mode 100644 pkg/daemon/keyexchange/zz_peer_key_buffer_alias_test.go create mode 100644 pkg/daemon/zz_direct_upgrade_keeps_relay_test.go diff --git a/CHANGELOG.md b/CHANGELOG.md index 0ebeaec1..566561f3 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -471,6 +471,25 @@ Detailed per-release notes are on the - **`pilotctl send-message` fails when the receiver does not acknowledge the message.** Every receiver answers a stored message with an ACK; with none, the command used to exit 0. +- **A peer whose direct path is dead stays on the relay.** After the + blackhole heuristic moved a peer to the relay, the relay probe loop put + it back on the direct path within 15 s: to let direct win again it has to + unpin the peer, and it did that with a call that clears the relay flag + too. Traffic then went to the dead address until three more silent sends + tripped the heuristic again, so the daemon spent roughly 75 s of every + 90 s sending into the void and logged `direct path silent, flipping to + relay` on a loop. Seen for over half an hour against a peer whose + registry endpoint was stale. The probe loop now removes only the pin; the + peer leaves the relay when direct packets from it actually arrive. +- **The cached key of a peer is no longer overwritten by the next packet.** + The key-exchange handler cached a peer's Ed25519 key as a slice of the + socket's reused receive buffer, so the following packet replaced the + cached key with its own bytes. The next key exchange from that peer then + mismatched the cache and made the daemon look the key up in the registry + from the packet read loop, holding up every other packet for the length + of that round trip; the log line `auth key exchange: peer pubkey updated + from registry` (97 in one six-hour session) was this, not peers changing + keys. The key is now copied. - **`-advertise-endpoint` survives a re-registration.** When the daemon re-registered (registry reconnect, transport watchdog recovery) it sent the tunnel socket's local address instead of the advertised endpoint, so diff --git a/pkg/daemon/daemon.go b/pkg/daemon/daemon.go index 431c692d..f9d1666a 100644 --- a/pkg/daemon/daemon.go +++ b/pkg/daemon/daemon.go @@ -6384,8 +6384,16 @@ func (d *Daemon) tryDirectUpgrade(nodeID uint32) { // A prior blackhole flip may have PINNED the peer to relay; ClearRelayOnDirect // will not promote a pinned peer. Unpin it — we've confirmed above it is not // registry relay-only, so direct is allowed to win on its merits. + // + // Only the pin goes. The peer stays on the relay until direct packets + // from it actually arrive. Clearing the relay flag here as well put + // every blackholed peer back on its dead direct path within one + // RelayProbeInterval of the flip, where it stayed until the blackhole + // heuristic tripped again (three more silent sends): about 75 s of + // every 90 s spent sending into the void, for as long as the direct + // path was down. if d.tunnels.IsRelayPinned(nodeID) { - d.tunnels.SetRelayPeerPinned(nodeID, false) + d.tunnels.UnpinRelayPeer(nodeID) } // Coordinate the punch (opens the conntrack pinhole on both NATs). diff --git a/pkg/daemon/keyexchange/handle.go b/pkg/daemon/keyexchange/handle.go index 2bfc6499..4f6a500e 100644 --- a/pkg/daemon/keyexchange/handle.go +++ b/pkg/daemon/keyexchange/handle.go @@ -32,7 +32,11 @@ func (m *Manager) HandleAuthFrame(data []byte, from *net.UDPAddr, fromRelay bool peerNodeID := binary.BigEndian.Uint32(data[0:4]) peerX25519PubKey := data[4:36] - peerEd25519PubKey := ed25519.PublicKey(data[36:68]) + // Copied, not sliced: data is the socket's reused receive buffer, and + // this key outlives the frame (peer-key cache, post-install event). + // A slice would be overwritten by the next packet read. + peerEd25519PubKey := make(ed25519.PublicKey, ed25519.PublicKeySize) + copy(peerEd25519PubKey, data[36:68]) signature := data[68:132] // Encryption (X25519 priv) must be enabled. diff --git a/pkg/daemon/keyexchange/keyexchange.go b/pkg/daemon/keyexchange/keyexchange.go index 729ed3c9..345fa0f8 100644 --- a/pkg/daemon/keyexchange/keyexchange.go +++ b/pkg/daemon/keyexchange/keyexchange.go @@ -490,9 +490,13 @@ func (m *Manager) PeerPubKeyCached(nodeID uint32) (ed25519.PublicKey, bool) { // SetPeerPubKey installs a cache entry directly. Used by handle paths // after verifying a packet-carried Ed25519 pubkey against the registry. +// The key is copied, so a caller holding a slice of a packet buffer +// cannot leave the cache pointing into memory the next read overwrites. func (m *Manager) SetPeerPubKey(nodeID uint32, pk ed25519.PublicKey) { + cp := make(ed25519.PublicKey, len(pk)) + copy(cp, pk) m.pubKeysMu.Lock() - m.peerPubKeys[nodeID] = pk + m.peerPubKeys[nodeID] = cp m.pubKeysMu.Unlock() } diff --git a/pkg/daemon/keyexchange/zz_peer_key_buffer_alias_test.go b/pkg/daemon/keyexchange/zz_peer_key_buffer_alias_test.go new file mode 100644 index 00000000..ae82cbd8 --- /dev/null +++ b/pkg/daemon/keyexchange/zz_peer_key_buffer_alias_test.go @@ -0,0 +1,77 @@ +// SPDX-License-Identifier: AGPL-3.0-or-later + +package keyexchange_test + +import ( + "bytes" + "net" + "testing" + + "github.com/pilot-protocol/pilotprotocol/pkg/daemon/keyexchange" +) + +// The tunnel read loop hands HandleAuthFrame a slice of its one reused +// receive buffer, valid only until the next packet is read. The peer's +// Ed25519 key was cached as a sub-slice of that buffer, so the next +// packet overwrote the cached key in place. Every consumer of the cache +// then saw garbage: the next PILA from the peer mismatched and forced a +// registry lookup on the read loop, and the key-bound trust check +// (Daemon.handshakeTrusts) compared the trust record against bytes of an +// unrelated packet. +func TestCachedPeerKeySurvivesReceiveBufferReuse(t *testing.T) { + t.Parallel() + + a := newPeer(t, 100) + b := newPeer(t, 200) + crossWireVerifyFuncs(a, b) + a.mgr.SetSender(func(uint32, *net.UDPAddr, []byte) error { return nil }) + b.mgr.SetSender(func(uint32, *net.UDPAddr, []byte) error { return nil }) + + bFrame := b.mgr.BuildAuthFrame() + if bFrame == nil { + t.Fatal("B.BuildAuthFrame returned nil") + } + + // Stand-in for the socket's receive buffer: the frame is read into + // it, handled, and the same bytes are then reused for the next packet. + recvBuf := make([]byte, 1500) + n := copy(recvBuf, bFrame) + want := append([]byte(nil), recvBuf[4+36:4+68]...) + + from := &net.UDPAddr{IP: net.IPv4(127, 0, 0, 1), Port: 4000} + if !a.mgr.HandleAuthFrame(recvBuf[4:n], from, false) { + t.Fatal("PILA from B rejected by A") + } + + // The next packet lands in the same buffer. + for i := range recvBuf { + recvBuf[i] = 0xAA + } + + got, ok := a.mgr.PeerPubKeyCached(b.id) + if !ok { + t.Fatal("no cached key for B after a verified PILA") + } + if !bytes.Equal(got, want) { + t.Fatalf("cached peer key changed when the receive buffer was reused:\n got %x\nwant %x", got, want) + } + + // The post-install hook receives the key too; a retained copy must + // not alias the buffer either. + var hooked []byte + a.mgr.Store().Drop(b.id) + a.mgr.SetPostInstallHook(func(ev keyexchange.PostInstallEvent) { hooked = ev.PeerEd25519 }) + n = copy(recvBuf, bFrame) + if !a.mgr.HandleAuthFrame(recvBuf[4:n], from, false) { + t.Fatal("second PILA from B rejected by A") + } + for i := range recvBuf { + recvBuf[i] = 0xBB + } + if hooked == nil { + t.Fatal("post-install hook did not fire") + } + if !bytes.Equal(hooked, want) { + t.Fatalf("key handed to the post-install hook changed when the receive buffer was reused:\n got %x\nwant %x", hooked, want) + } +} diff --git a/pkg/daemon/routing/relay.go b/pkg/daemon/routing/relay.go index 1a844cb7..25cd15f7 100644 --- a/pkg/daemon/routing/relay.go +++ b/pkg/daemon/routing/relay.go @@ -31,6 +31,18 @@ func (m *Manager) SetRelayPeerPinned(nodeID uint32, relay bool) { m.mu.Unlock() } +// UnpinRelayPeer clears the pin on a peer and leaves its relay flag as it +// is. Traffic keeps using the relay; ClearRelayOnDirect may now move the +// peer back to direct once DirectClearsRequired direct packets arrive. +// SetRelayPeerPinned(id, false) is not a substitute: it clears the relay +// flag too, which sends traffic direct before anything has shown the +// direct path works. +func (m *Manager) UnpinRelayPeer(nodeID uint32) { + m.mu.Lock() + delete(m.relayPinned, nodeID) + m.mu.Unlock() +} + // IsRelayPeer reports whether the peer is currently in relay mode. func (m *Manager) IsRelayPeer(nodeID uint32) bool { m.mu.RLock() diff --git a/pkg/daemon/tunnel.go b/pkg/daemon/tunnel.go index cc20d5d4..01375335 100644 --- a/pkg/daemon/tunnel.go +++ b/pkg/daemon/tunnel.go @@ -2176,6 +2176,12 @@ func (tm *TunnelManager) clearRelayOnDirectLocked(peerNodeID uint32, from *net.U return tm.routing.ClearRelayOnDirect(peerNodeID, from) } +// UnpinRelayPeer clears a peer's relay pin and keeps it on the relay. +// Thin shim over routing.Manager.UnpinRelayPeer. +func (tm *TunnelManager) UnpinRelayPeer(nodeID uint32) { + tm.routing.UnpinRelayPeer(nodeID) +} + // SetRelayPeerPinned is like SetRelayPeer but also marks the relay flag // as authoritative — ClearRelayOnDirect will never auto-flip a pinned // peer back to direct based on observed packet sources. Thin shim over diff --git a/pkg/daemon/zz_direct_upgrade_keeps_relay_test.go b/pkg/daemon/zz_direct_upgrade_keeps_relay_test.go new file mode 100644 index 00000000..9fd26d40 --- /dev/null +++ b/pkg/daemon/zz_direct_upgrade_keeps_relay_test.go @@ -0,0 +1,130 @@ +// SPDX-License-Identifier: AGPL-3.0-or-later + +package daemon + +import ( + "net" + "testing" + "time" +) + +// A peer whose direct path went silent is flipped to the relay and +// pinned there. relayProbeLoop then calls tryDirectUpgrade every +// RelayProbeInterval to give direct another chance. It has to unpin the +// peer for that, and it used SetRelayPeerPinned(id, false), which clears +// the relay flag as well. The peer was back on its dead direct path within +// 15 s of every flip and stayed there until three more silent sends +// tripped the blackhole heuristic again. +// +// Seen live on 2026-10-01 against a peer whose registry endpoint was +// stale: "direct path silent, flipping to relay" every ~90 s for over +// half an hour, with no "relay→direct auto-cleared" between the flips. +func TestDirectUpgradeUnpinsWithoutLeavingTheRelay(t *testing.T) { + d := New(Config{}) + t.Cleanup(func() { d.tunnels.Close() }) + + const peer uint32 = 0x0002BBE4 + peerConn := addPeerOnDaemon(t, d, peer) + t.Cleanup(func() { peerConn.Close() }) + + beacon, err := net.ListenUDP("udp", &net.UDPAddr{IP: net.ParseIP("127.0.0.1"), Port: 0}) + if err != nil { + t.Fatalf("beacon listen: %v", err) + } + t.Cleanup(func() { beacon.Close() }) + if err := d.tunnels.SetBeaconAddr(beacon.LocalAddr().String()); err != nil { + t.Fatalf("SetBeaconAddr: %v", err) + } + + // The registry says the peer is directly reachable (not relay-only), + // so tryDirectUpgrade goes ahead without a registry round trip. + d.cacheResolve(peer, map[string]interface{}{ + "real_addr": peerConn.LocalAddr().String(), + }) + + // State after a blackhole flip: on the relay, pinned. + d.tunnels.SetRelayPeerPinned(peer, true) + + d.tryDirectUpgrade(peer) + + if d.tunnels.IsRelayPinned(peer) { + t.Fatal("pin must be cleared so a working direct path can win") + } + if !d.tunnels.IsRelayPeer(peer) { + t.Fatal("peer left the relay before any direct packet arrived from it") + } + + // The upgrade itself still works: direct packets from the peer move it + // back, and only they do. + from := peerConn.LocalAddr().(*net.UDPAddr) + for i := 1; i < directClearsRequired; i++ { + if d.tunnels.routing.ClearRelayOnDirect(peer, from) { + t.Fatalf("relay cleared after %d direct packets, want %d", i, directClearsRequired) + } + } + if !d.tunnels.routing.ClearRelayOnDirect(peer, from) { + t.Fatalf("relay not cleared after %d direct packets", directClearsRequired) + } + if d.tunnels.IsRelayPeer(peer) { + t.Fatal("peer still on the relay after the direct path was confirmed") + } +} + +// The blackhole heuristic and the probe loop must not fight. With the +// direct path dead, one flip keeps the peer on the relay across any +// number of probe ticks; writes do not flip it again. +func TestBlackholedPeerStaysOnRelayAcrossProbeTicks(t *testing.T) { + d := New(Config{}) + t.Cleanup(func() { d.tunnels.Close() }) + + const peer uint32 = 0x0002BBE5 + peerConn := addPeerOnDaemon(t, d, peer) + t.Cleanup(func() { peerConn.Close() }) + + beacon, err := net.ListenUDP("udp", &net.UDPAddr{IP: net.ParseIP("127.0.0.1"), Port: 0}) + if err != nil { + t.Fatalf("beacon listen: %v", err) + } + t.Cleanup(func() { beacon.Close() }) + if err := d.tunnels.SetBeaconAddr(beacon.LocalAddr().String()); err != nil { + t.Fatalf("SetBeaconAddr: %v", err) + } + d.cacheResolve(peer, map[string]interface{}{ + "real_addr": peerConn.LocalAddr().String(), + }) + + // Nothing has come from the peer directly for a long time. + d.tunnels.routing.RecordDirectRecv(peer, time.Now().Add(-10*time.Minute)) + addr := peerConn.LocalAddr().(*net.UDPAddr) + frame := []byte("PILS-not-a-real-frame") + + flips := 0 + write := func() { + was := d.tunnels.IsRelayPeer(peer) + _ = d.tunnels.writeFrame(peer, addr, frame) + if !was && d.tunnels.IsRelayPeer(peer) { + flips++ + } + } + + for i := 0; i < blackholeMissesRequired; i++ { + write() + } + if flips != 1 || !d.tunnels.IsRelayPeer(peer) { + t.Fatalf("setup: want one flip to the relay after %d silent sends, got %d (relay=%v)", + blackholeMissesRequired, flips, d.tunnels.IsRelayPeer(peer)) + } + + for tick := 0; tick < 3; tick++ { + d.tryDirectUpgrade(peer) + for i := 0; i < blackholeMissesRequired+1; i++ { + write() + } + } + if flips != 1 { + t.Fatalf("peer flipped to the relay %d times; the probe loop keeps putting it back on the dead direct path", flips) + } + if !d.tunnels.IsRelayPeer(peer) { + t.Fatal("peer is not on the relay although its direct path never answered") + } +}