wgengine/magicsock: fix race condition in tests.

AFAICT this was always present, the log read mid-execution was never safe.
But it seems like the recent magicsock refactoring made the race much
more likely.

Signed-off-by: David Anderson <danderson@tailscale.com>
This commit is contained in:
David Anderson 2021-09-05 17:41:23 -07:00
parent 000f90d4d7
commit efe8020dfa

View File

@ -1315,20 +1315,26 @@ func BenchmarkReceiveFrom_Native(b *testing.B) {
} }
} }
// logBufWriterMu serializes writes made by logBufWriter. type bufLog struct {
var logBufWriterMu sync.Mutex sync.Mutex
buf bytes.Buffer
}
func logBufWriter(buf *bytes.Buffer) logger.Logf { func (b *bufLog) Logf(format string, args ...interface{}) {
return func(format string, a ...interface{}) { b.Lock()
logBufWriterMu.Lock() defer b.Unlock()
defer logBufWriterMu.Unlock() fmt.Fprintf(&b.buf, format, args...)
fmt.Fprintf(buf, format, a...) if !bytes.HasPrefix(b.buf.Bytes(), []byte("\n")) {
if !bytes.HasSuffix(buf.Bytes(), []byte("\n")) { b.buf.WriteByte('\n')
buf.WriteByte('\n')
}
} }
} }
func (b *bufLog) String() string {
b.Lock()
defer b.Unlock()
return b.buf.String()
}
// Test that a netmap update where node changes its node key but // Test that a netmap update where node changes its node key but
// doesn't change its disco key doesn't result in a broken state. // doesn't change its disco key doesn't result in a broken state.
// //
@ -1336,8 +1342,8 @@ func logBufWriter(buf *bytes.Buffer) logger.Logf {
func TestSetNetworkMapChangingNodeKey(t *testing.T) { func TestSetNetworkMapChangingNodeKey(t *testing.T) {
conn := newTestConn(t) conn := newTestConn(t)
t.Cleanup(func() { conn.Close() }) t.Cleanup(func() { conn.Close() })
var logBuf bytes.Buffer var buf bufLog
conn.logf = logBufWriter(&logBuf) conn.logf = buf.Logf
conn.SetPrivateKey(wgkey.Private{0: 1}) conn.SetPrivateKey(wgkey.Private{0: 1})
@ -1376,7 +1382,7 @@ func TestSetNetworkMapChangingNodeKey(t *testing.T) {
t.Fatalf("discoEndpoint public key = %q; want %q", de.publicKey[:], nodeKey2[:]) t.Fatalf("discoEndpoint public key = %q; want %q", de.publicKey[:], nodeKey2[:])
} }
log := logBuf.String() log := buf.String()
wantSub := map[string]int{ wantSub := map[string]int{
"magicsock: got updated network map; 1 peers": 2, "magicsock: got updated network map; 1 peers": 2,
"magicsock: disco key discokey:0000000000000000000000000000000000000000000000000000000000000001 changed from node key [TksxA] to [TksyA]": 1, "magicsock: disco key discokey:0000000000000000000000000000000000000000000000000000000000000001 changed from node key [TksxA] to [TksyA]": 1,
@ -1395,8 +1401,8 @@ func TestSetNetworkMapChangingNodeKey(t *testing.T) {
func TestRebindStress(t *testing.T) { func TestRebindStress(t *testing.T) {
conn := newTestConn(t) conn := newTestConn(t)
var logBuf bytes.Buffer var buf bufLog
conn.logf = logBufWriter(&logBuf) conn.logf = buf.Logf
closed := false closed := false
t.Cleanup(func() { t.Cleanup(func() {
@ -1448,7 +1454,7 @@ func TestRebindStress(t *testing.T) {
err := <-errc err := <-errc
if err != nil { if err != nil {
t.Fatalf("Got ReceiveIPv4 error: %v (is closed = %v). Log:\n%s", err, errors.Is(err, net.ErrClosed), logBuf.Bytes()) t.Fatalf("Got ReceiveIPv4 error: %v (is closed = %v). Log:\n%s", err, errors.Is(err, net.ErrClosed), buf.String())
} }
} }