ci: Improve peer logging to help identify race

kylecarbs · kylecarbs · commit 54d2cc1e8164 · 2022-01-30T01:00:54.000Z
diff --git a/peer/conn.go b/peer/conn.go
@@ -4,6 +4,7 @@ import (
 	"bytes"
 	"context"
 	"crypto/rand"
+	"crypto/sha256"
 	"io"
 	"sync"
 	"time"
@@ -311,15 +312,22 @@ func (c *Conn) negotiate() {
 	c.pendingCandidatesMutex.Lock()
 	defer c.pendingCandidatesMutex.Unlock()
 	for _, pendingCandidate := range c.pendingRemoteCandidates {
-		c.opts.Logger.Debug(context.Background(), "flushing remote candidate")
+		hash := sha256.Sum224([]byte(pendingCandidate.Candidate))
+		c.opts.Logger.Debug(context.Background(), "flushing buffered remote candidate",
+			slog.F("hash", hash),
+			slog.F("length", len(pendingCandidate.Candidate)),
+		)
 		err := c.rtc.AddICECandidate(pendingCandidate)
 		if err != nil {
-			_ = c.CloseWithError(xerrors.Errorf("flush pending candidates: %w", err))
+			_ = c.CloseWithError(xerrors.Errorf("flush pending remote candidate: %w", err))
 			return
 		}
 	}
+	c.opts.Logger.Debug(context.Background(), "flushed buffered remote candidates",
+		slog.F("count", len(c.pendingRemoteCandidates)),
+	)
 	c.pendingCandidatesFlushed = true
-	c.opts.Logger.Debug(context.Background(), "flushed remote candidates")
+	c.pendingRemoteCandidates = make([]webrtc.ICECandidateInit, 0)
 }
 
 // LocalCandidate returns a channel that emits when a local candidate
@@ -332,12 +340,16 @@ func (c *Conn) LocalCandidate() <-chan webrtc.ICECandidateInit {
 func (c *Conn) AddRemoteCandidate(i webrtc.ICECandidateInit) error {
 	c.pendingCandidatesMutex.Lock()
 	defer c.pendingCandidatesMutex.Unlock()
+	fields := []slog.Field{
+		slog.F("hash", sha256.Sum224([]byte(i.Candidate))),
+		slog.F("length", len(i.Candidate)),
+	}
 	if !c.pendingCandidatesFlushed {
-		c.opts.Logger.Debug(context.Background(), "adding remote candidate to buffer")
+		c.opts.Logger.Debug(context.Background(), "bufferring remote candidate", fields...)
 		c.pendingRemoteCandidates = append(c.pendingRemoteCandidates, i)
 		return nil
 	}
-	c.opts.Logger.Debug(context.Background(), "adding remote candidate")
+	c.opts.Logger.Debug(context.Background(), "adding remote candidate", fields...)
 	return c.rtc.AddICECandidate(i)
 }
 
