diff --git a/ipn/ipnlocal/loglines_test.go b/ipn/ipnlocal/loglines_test.go index 66cc60a8d..cdd3e33f7 100644 --- a/ipn/ipnlocal/loglines_test.go +++ b/ipn/ipnlocal/loglines_test.go @@ -15,6 +15,7 @@ "tailscale.com/tailcfg" "tailscale.com/tstest" "tailscale.com/types/key" + "tailscale.com/types/logger" "tailscale.com/types/persist" "tailscale.com/wgengine" ) @@ -30,6 +31,11 @@ func TestLocalLogLines(t *testing.T) { }) defer logListen.Close() + // Put a rate-limiter between the components below and the + // logListen tracker to verify that the rate-limiter isn't + // eating these. + logf := logger.RateLimitedFnWithClock(logListen.Logf, 5*time.Second, 1, 10, time.Now) + logid := func(hex byte) logtail.PublicID { var ret logtail.PublicID for i := 0; i < len(ret); i++ { @@ -41,12 +47,12 @@ func TestLocalLogLines(t *testing.T) { // set up a LocalBackend, super bare bones. No functional data. store := &ipn.MemoryStore{} - e, err := wgengine.NewFakeUserspaceEngine(logListen.Logf, 0) + e, err := wgengine.NewFakeUserspaceEngine(logf, 0) if err != nil { t.Fatal(err) } - lb, err := NewLocalBackend(logListen.Logf, idA.String(), store, e) + lb, err := NewLocalBackend(logf, idA.String(), store, e) if err != nil { t.Fatal(err) } @@ -75,17 +81,30 @@ func TestLocalLogLines(t *testing.T) { t.Run("after_prefs", testWantRemain("[v1] peer keys: %s", "[v1] v%v peers: %v")) // log peers, peer keys - status := &wgengine.Status{ + lb.mu.Lock() + lb.parseWgStatusLocked(&wgengine.Status{ Peers: []ipnstate.PeerStatusLite{{ TxBytes: 10, RxBytes: 10, LastHandshake: time.Now(), NodeKey: tailcfg.NodeKey(key.NewPrivate()), }}, - } - lb.mu.Lock() - lb.parseWgStatusLocked(status) + }) lb.mu.Unlock() t.Run("after_peers", testWantRemain()) + + // Log it again to see whether it's dup-suppressed. + logListen.Reset() + lb.mu.Lock() + lb.parseWgStatusLocked(&wgengine.Status{ + Peers: []ipnstate.PeerStatusLite{{ + TxBytes: 11, + RxBytes: 12, + LastHandshake: time.Now(), + NodeKey: tailcfg.NodeKey(key.NewPrivate()), + }}, + }) + lb.mu.Unlock() + t.Run("after_second_peer_status", testWantRemain()) } diff --git a/tstest/log.go b/tstest/log.go index b7750cf12..4acf10d0c 100644 --- a/tstest/log.go +++ b/tstest/log.go @@ -107,6 +107,13 @@ func (lt *LogLineTracker) Check() []string { return notSeen } +// Reset forgets everything that it's seen. +func (lt *LogLineTracker) Reset() { + lt.mu.Lock() + defer lt.mu.Unlock() + lt.seen = map[string]bool{} +} + // Close closes lt. After calling Close, calls to Logf become no-ops. func (lt *LogLineTracker) Close() { lt.mu.Lock() diff --git a/types/logger/logger.go b/types/logger/logger.go index 13809d31e..1e121f32a 100644 --- a/types/logger/logger.go +++ b/types/logger/logger.go @@ -67,6 +67,8 @@ type limitData struct { var rateFree = []string{ "magicsock: disco: ", "magicsock: CreateEndpoint:", + "peer keys: %s", + "v%v peers: %v", } // RateLimitedFn is a wrapper for RateLimitedFnWithClock that includes the