net/tstun: rate limit "self disco out packet" logging

When this happens, it is incredibly noisy in the logs.
It accounts for about a third of all remaining
"unexpected" log lines from a recent investigation.

It's not clear that we know how to fix this,
we have a functioning workaround,
and we now have a (cheap and efficient) metric for this
that we can use for measurements.

So reduce the logging to approximately once per minute.

Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>

cmd/tailscaled/depaware.txt

@@ -224,7 +224,7 @@ tailscale.com/cmd/tailscaled dependencies: (generated by github.com/tailscale/de
         tailscale.com/types/netmap                                   from tailscale.com/control/controlclient+
         tailscale.com/types/nettype                                  from tailscale.com/wgengine/magicsock
         tailscale.com/types/opt                                      from tailscale.com/control/controlclient+
-        tailscale.com/types/pad32                                    from tailscale.com/derp+
+        tailscale.com/types/pad32                                    from tailscale.com/derp
         tailscale.com/types/persist                                  from tailscale.com/control/controlclient+
         tailscale.com/types/preftype                                 from tailscale.com/ipn+
         tailscale.com/types/structs                                  from tailscale.com/control/controlclient+

net/tstun/wrap.go

@@ -26,7 +26,6 @@ import (
 	"tailscale.com/types/ipproto"
 	"tailscale.com/types/key"
 	"tailscale.com/types/logger"
-	"tailscale.com/types/pad32"
 	"tailscale.com/util/clientmetric"
 	"tailscale.com/wgengine/filter"
 )
@@ -68,14 +67,17 @@ type FilterFunc func(*packet.Parsed, *Wrapper) filter.Response
 
 // Wrapper augments a tun.Device with packet filtering and injection.
 type Wrapper struct {
-	logf logger.Logf
+	logf        logger.Logf
+	limitedLogf logger.Logf // aggressively rate-limited logf used for potentially high volume errors
 	// tdev is the underlying Wrapper device.
 	tdev  tun.Device
 	isTAP bool // whether tdev is a TAP device
 
 	closeOnce sync.Once
 
-	_                  pad32.Four
+	// lastActivityAtomic is read/written atomically.
+	// On 32 bit systems, if the fields above change,
+	// you might need to add a pad32.Four field here.
 	lastActivityAtomic mono.Time // time of last send or receive
 
 	destIPActivity atomic.Value // of map[netaddr.IP]func()
@@ -168,10 +170,12 @@ func Wrap(logf logger.Logf, tdev tun.Device) *Wrapper {
 }
 
 func wrap(logf logger.Logf, tdev tun.Device, isTAP bool) *Wrapper {
+	logf = logger.WithPrefix(logf, "tstun: ")
 	tun := &Wrapper{
-		logf:  logger.WithPrefix(logf, "tstun: "),
+		logf:        logf,
-		isTAP: isTAP,
+		limitedLogf: logger.RateLimitedFn(logf, 1*time.Minute, 2, 10),
-		tdev:  tdev,
+		isTAP:       isTAP,
+		tdev:        tdev,
 		// bufferConsumed is conceptually a condition variable:
 		// a goroutine should not block when setting it, even with no listeners.
 		bufferConsumed: make(chan struct{}, 1),
@@ -421,7 +425,7 @@ func (t *Wrapper) filterOut(p *packet.Parsed) filter.Response {
 	// macOS in Network Extension mode might be.
 	if p.IPProto == ipproto.UDP && // disco is over UDP; avoid isSelfDisco call for TCP/etc
 		t.isSelfDisco(p) {
-		t.logf("[unexpected] received self disco out packet over tstun; dropping")
+		t.limitedLogf("[unexpected] received self disco out packet over tstun; dropping")
 		metricPacketOutDropSelfDisco.Add(1)
 		return filter.DropSilently
 	}
@@ -535,7 +539,7 @@ func (t *Wrapper) filterIn(buf []byte) filter.Response {
 	// macOS in Network Extension mode might be.
 	if p.IPProto == ipproto.UDP && // disco is over UDP; avoid isSelfDisco call for TCP/etc
 		t.isSelfDisco(p) {
-		t.logf("[unexpected] received self disco in packet over tstun; dropping")
+		t.limitedLogf("[unexpected] received self disco in packet over tstun; dropping")
 		metricPacketInDropSelfDisco.Add(1)
 		return filter.DropSilently
 	}

net/tstun/wrap_test.go

@@ -495,7 +495,7 @@ func TestPeerAPIBypass(t *testing.T) {
 func TestFilterDiscoLoop(t *testing.T) {
 	var memLog tstest.MemLogger
 	discoPub := key.DiscoPublicFromRaw32(mem.B([]byte{1: 1, 2: 2, 31: 0}))
-	tw := &Wrapper{logf: memLog.Logf}
+	tw := &Wrapper{logf: memLog.Logf, limitedLogf: memLog.Logf}
 	tw.SetDiscoKey(discoPub)
 	uh := packet.UDP4Header{
 		IP4Header: packet.IP4Header{