Tolerate ErrDumpInterrupted when listing tun addresses (#1835)

e2e/recovery_timing_test.go

@@ -0,0 +1,136 @@
+//go:build e2e_testing
+// +build e2e_testing
+
+package e2e
+
+import (
+	"testing"
+	"time"
+
+	"github.com/slackhq/nebula"
+	"github.com/slackhq/nebula/cert"
+	"github.com/slackhq/nebula/cert_test"
+	"github.com/slackhq/nebula/e2e/router"
+	"github.com/slackhq/nebula/udp"
+)
+
+// TestRecoveryTiming measures how long a tunnel takes to come back after the peer stops accepting our traffic,
+// which is what a laptop waking on a new network looks like from the peer's side: its NAT has no state for where
+// we are now, so everything we send disappears.
+//
+// It is a measurement, not a pass/fail assertion. Recovery is timed to the moment the peer punches back at us,
+// since that is when its NAT opens and the tunnel is usable again.
+//
+//	go test -tags e2e_testing -v -run TestRecoveryTiming ./e2e/
+func TestRecoveryTiming(t *testing.T) {
+	for _, tc := range []struct {
+		name   string
+		rebind bool
+	}{
+		{"no trigger", false},
+		{"rebind counter", true},
+	} {
+		t.Run(tc.name, func(t *testing.T) {
+			d, lost := measureRecovery(t, tc.rebind)
+			t.Logf("RESULT %-16s recovered in %-9v (%d packets lost)", tc.name, d.Round(time.Millisecond), lost)
+		})
+	}
+}
+
+// measureRecovery returns how long until the peer punched back, and how many of our packets died meanwhile. When
+// rebind is true we call RebindUDPServer once the tunnel goes dark, which is what the darwin network change
+// monitor does and what iOS has always done. When false, nothing tells nebula anything is wrong.
+func measureRecovery(t *testing.T, rebind bool) (time.Duration, int) {
+	t.Helper()
+	ca, _, caKey, _ := cert_test.NewTestCaCert(cert.Version2, cert.Curve_CURVE25519, time.Now(), time.Now().Add(10*time.Minute), nil, nil, []string{})
+
+	lhControl, lhVpnIpNet, lhUdpAddr, _ := newSimpleServer(cert.Version2, ca, caKey, "lh", "10.128.0.1/24", m{
+		"lighthouse": m{"am_lighthouse": true},
+	})
+
+	peerCfg := m{
+		"lighthouse": m{
+			"hosts":    []any{lhVpnIpNet[0].Addr().String()},
+			"interval": 600,
+			"local_allow_list": m{
+				"10.0.0.0/24": true,
+				"::/0":        false,
+			},
+		},
+		"static_host_map": m{
+			lhVpnIpNet[0].Addr().String(): []any{lhUdpAddr.String()},
+		},
+	}
+
+	myControl, myVpnIpNet, myUdpAddr, _ := newSimpleServer(cert.Version2, ca, caKey, "me", "10.128.0.2/24", peerCfg)
+	theirControl, theirVpnIpNet, theirUdpAddr, _ := newSimpleServer(cert.Version2, ca, caKey, "them", "10.128.0.3/24", peerCfg)
+
+	r := router.NewR(t, lhControl, myControl, theirControl)
+	defer r.RenderFlow()
+	defer func() {
+		lhControl.Stop()
+		myControl.Stop()
+		theirControl.Stop()
+	}()
+
+	lhControl.Start()
+	myControl.Start()
+	theirControl.Start()
+	r.RouteFor(time.Millisecond * 500)
+
+	myControl.InjectLightHouseAddr(theirVpnIpNet[0].Addr(), theirUdpAddr)
+	theirControl.InjectLightHouseAddr(myVpnIpNet[0].Addr(), myUdpAddr)
+
+	myControl.InjectTunPacket(BuildTunUDPPacket(theirVpnIpNet[0].Addr(), 80, myVpnIpNet[0].Addr(), 80, []byte("establish")))
+	r.RouteFor(time.Second)
+	if myControl.GetHostInfoByVpnAddr(theirVpnIpNet[0].Addr(), false) == nil {
+		t.Fatal("failed to establish the tunnel we are measuring")
+	}
+	r.RouteFor(time.Millisecond * 500)
+
+	// From here the peer's NAT has no state for us, everything we send it disappears
+	start := time.Now()
+	blackholed := 0
+	var recovered time.Duration
+
+	if rebind {
+		myControl.RebindUDPServer()
+	}
+
+	// Keep the tun busy the way someone retrying a stalled connection would
+	stop := make(chan struct{})
+	defer close(stop)
+	go func() {
+		tick := time.NewTicker(time.Millisecond * 200)
+		defer tick.Stop()
+		for {
+			select {
+			case <-stop:
+				return
+			case <-tick.C:
+				myControl.InjectTunPacket(BuildTunUDPPacket(
+					theirVpnIpNet[0].Addr(), 80, myVpnIpNet[0].Addr(), 80, []byte("retry")))
+			}
+		}
+	}()
+
+	r.RouteForAllExitFuncOrTimeout(time.Second*30, func(p *udp.Packet, c *nebula.Control) router.ExitType {
+		if c == theirControl && p.From == myControl.GetUDPAddr() {
+			blackholed++
+			return router.Drop
+		}
+
+		// The peer reaching us directly is the moment its NAT opened, whether that is a punch or a handshake
+		if c == myControl && p.From == theirUdpAddr {
+			recovered = time.Since(start)
+			return router.RouteAndExit
+		}
+
+		return router.KeepRouting
+	})
+
+	if recovered == 0 {
+		t.Fatalf("no recovery within 30s (%d packets blackholed)", blackholed)
+	}
+	return recovered, blackholed
+}

e2e/router/router.go

@@ -153,6 +153,9 @@ const (
 	ExitNow ExitType = 1
 	// RouteAndExit routes this packet and exits immediately afterwards
 	RouteAndExit ExitType = 2
+	// Drop discards this packet without delivering it and keeps routing. Use it to simulate a blackhole, such as
+	// a restrictive NAT refusing traffic from an address it has not seen.
+	Drop ExitType = 3
 )
 
 type ExitFunc func(packet *udp.Packet, receiver *nebula.Control) ExitType
@@ -163,7 +166,9 @@ type ExitFunc func(packet *udp.Packet, receiver *nebula.Control) ExitType
 func NewR(t testing.TB, controls ...*nebula.Control) *R {
 	ctx, cancel := context.WithCancel(context.Background())
 
-	if err := os.MkdirAll("mermaid", 0755); err != nil {
+	// t.Name() contains a slash for subtests, so the flow log can land in a nested directory
+	fn := filepath.Join("mermaid", fmt.Sprintf("%s.md", t.Name()))
+	if err := os.MkdirAll(filepath.Dir(fn), 0755); err != nil {
 		panic(err)
 	}
 
@@ -174,7 +179,7 @@ func NewR(t testing.TB, controls ...*nebula.Control) *R {
 		outNat:       make(map[outNatKey]netip.AddrPort),
 		flow:         []flowEntry{},
 		ignoreFlows:  []ignoreFlow{},
-		fn:           filepath.Join("mermaid", fmt.Sprintf("%s.md", t.Name())),
+		fn:           fn,
 		t:            t,
 		cancelRender: cancel,
 	}
@@ -687,6 +692,10 @@ func (r *R) RouteExitFunc(sender *nebula.Control, whatDo ExitFunc) {
 			p.Release()
 			return
 
+		case Drop:
+			// Record it so the flow log shows the attempt, but never hand it to the receiver
+			r.unlockedInjectFlow(sender, receiver, p, false)
+
 		case KeepRouting:
 			fp := r.unlockedInjectFlow(sender, receiver, p, false)
 			receiver.InjectUDPPacket(p)
@@ -779,6 +788,10 @@ func (r *R) RouteForAllExitFuncOrTimeout(timeout time.Duration, whatDo ExitFunc)
 			p.Release()
 			return true
 
+		case Drop:
+			// Record it so the flow log shows the attempt, but never hand it to the receiver
+			r.unlockedInjectFlow(cm[x], receiver, p, false)
+
 		case KeepRouting:
 			fp := r.unlockedInjectFlow(cm[x], receiver, p, false)
 			receiver.InjectUDPPacket(p)
@@ -884,6 +897,10 @@ func (r *R) RouteForAllExitFunc(whatDo ExitFunc) {
 			p.Release()
 			return
 
+		case Drop:
+			// Record it so the flow log shows the attempt, but never hand it to the receiver
+			r.unlockedInjectFlow(cm[x], receiver, p, false)
+
 		case KeepRouting:
 			fp := r.unlockedInjectFlow(cm[x], receiver, p, false)
 			receiver.InjectUDPPacket(p)

overlay/tun_linux.go

@@ -5,6 +5,7 @@ package overlay
 
 import (
 	"encoding/binary"
+	"errors"
 	"fmt"
 	"io"
 	"log/slog"
@@ -483,7 +484,16 @@ func (t *tun) addIPs(link netlink.Link) error {
 	//iterate over remainder, remove whoever shouldn't be there
 	al, err := netlink.AddrList(link, netlink.FAMILY_ALL)
 	if err != nil {
-		return fmt.Errorf("failed to get tun address list: %s", err)
+		//RTM_GETADDR dumps the whole system, so any concurrent address change
+		//interrupts it - including the kernel's async tentative->preferred
+		//flip of an IPv6 address the AddrReplace calls above just added,
+		//which makes this a race against our own setup. Partial results are
+		//still returned; the worst case is a stale address surviving until
+		//the next config reload, which beats failing startup over it.
+		if !errors.Is(err, netlink.ErrDumpInterrupted) {
+			return fmt.Errorf("failed to get tun address list: %s", err)
+		}
+		t.l.Warn("tun address list dump was interrupted, stale addresses may remain")
 	}
 
 	for i := range al {