Fix network data logging

pkg/logging/logging.go

@@ -3,6 +3,7 @@ package logging
 import (
 	"context"
 	"encoding"
+	"encoding/base64"
 	"fmt"
 	"io"
 	"log/slog"
@@ -201,3 +202,16 @@ func TxID(t txIDGetter, scheme scheme) slog.Attr {
 	var val slog.LogValuer = txIDSlogValuer{t: t, scheme: scheme}
 	return slog.Any("txID", val)
 }
+
+type base64SlogValuer []byte
+
+func (v base64SlogValuer) LogValue() slog.Value {
+	return slog.StringValue(base64.StdEncoding.EncodeToString(v))
+}
+
+// Data returns a slog.Attr that lazily encodes the given bytes as base64 string.
+// Encoding happens only if the record is actually handled.
+func Data(data []byte) slog.Attr {
+	var val slog.LogValuer = base64SlogValuer(data)
+	return slog.Any("data", val)
+}

pkg/logging/logging_internal_test.go

@@ -104,3 +104,45 @@ func TestError(t *testing.T) {
 		})
 	}
 }
+
+func TestData(t *testing.T) {
+	data := []byte{0x00, 0x01, 0xfe, 0xff, 'a', 'b', 'c'}
+	const expected = "AAH+/2FiYw=="
+	for _, test := range []struct {
+		name    string
+		handler func(w *bytes.Buffer) slog.Handler
+		check   func(t *testing.T, out []byte)
+	}{
+		{
+			name:    "text",
+			handler: func(w *bytes.Buffer) slog.Handler { return slog.NewTextHandler(w, nil) },
+			check: func(t *testing.T, out []byte) {
+				assert.Contains(t, string(out), `data="`+expected+`"`)
+			},
+		},
+		{
+			name:    "json",
+			handler: func(w *bytes.Buffer) slog.Handler { return slog.NewJSONHandler(w, nil) },
+			check: func(t *testing.T, out []byte) {
+				var m map[string]any
+				require.NoError(t, json.Unmarshal(out, &m))
+				assert.Equal(t, expected, m["data"])
+			},
+		},
+	} {
+		t.Run(test.name, func(t *testing.T) {
+			buf := new(bytes.Buffer)
+			slog.New(test.handler(buf)).Info("test", Data(data))
+			test.check(t, buf.Bytes())
+		})
+	}
+}
+
+func BenchmarkDataDiscarded(b *testing.B) {
+	data := make([]byte, 1<<20)
+	l := slog.New(slog.DiscardHandler)
+	b.ReportAllocs()
+	for b.Loop() {
+		l.Debug("test", Data(data))
+	}
+}

pkg/networking/session.go

@@ -4,7 +4,6 @@ import (
 	"bufio"
 	"bytes"
 	"context"
-	"encoding/base64"
 	"errors"
 	"fmt"
 	"io"
@@ -196,7 +195,7 @@ func (s *Session) waitForSend(data []byte) error {
 	defer s.tp.Put(timer)
 
 	if s.logger.Enabled(s.ctx, slog.LevelDebug) {
-		s.logger.Debug("Sending data", "data", base64.StdEncoding.EncodeToString(data))
+		s.logger.Debug("Sending data", logging.Data(data))
 	}
 	select {
 	case s.sendCh <- newSendPacket(data, errCh):
@@ -252,9 +251,7 @@ func (s *Session) sendLoop() error {
 			if dataBuf.Len() > 0 {
 				data := dataBuf.Bytes()
 				if s.logger.Enabled(s.ctx, slog.LevelDebug) {
-					s.logger.Debug("Sending data to connection",
-						"len", len(data),
-						"data", base64.StdEncoding.EncodeToString(data))
+					s.logger.Debug("Sending data to connection", slog.Int("len", len(data)), logging.Data(data))
 				}
 				written, err := s.writeConnIfNotClosed(data)
 				if err != nil {
@@ -402,8 +399,7 @@ func (s *Session) readMessagePayload(hdr Header, conn io.Reader) error {
 	// The slice of bytes passed into the handler is only valid for the duration of the handler invocation.
 	// So inside the handler better deserialize message or make a copy of the bytes.
 	if s.logger.Enabled(s.ctx, slog.LevelDebug) {
-		s.logger.Debug("Invoking OnReceive handler", "message",
-			base64.StdEncoding.EncodeToString(s.receiveBuffer.Bytes()))
+		s.logger.Debug("Invoking OnReceive handler", logging.Data(s.receiveBuffer.Bytes()))
 	}
 	s.config.handler.OnReceive(s, s.receiveBuffer) // Invoke OnReceive handler.
 	return nil

pkg/p2p/peer/handle.go

@@ -76,7 +76,9 @@ func Handle(ctx context.Context, peer Peer, parent Parent, remote Remote, logger
 
 		case bb := <-remote.FromCh:
 			if !errSentToParent {
-				dl.Debug("Receiving from network", "peer", peer.ID(), "data", proto.B64Bytes(bb.Bytes()))
+				if dl.Enabled(ctx, slog.LevelDebug) {
+					dl.Debug("Receiving from network", slog.Any("peer", peer.ID()), logging.Data(bb.Bytes()))
+				}
 				err := bytesToMessage(bb.Bytes(), parent.MessageCh, peer, logger)
 				if err != nil {
 					out := InfoMessage{Peer: peer, Value: &InternalErr{Err: err}}

pkg/p2p/peer/peer_impl.go

@@ -85,7 +85,9 @@ func (a *PeerImpl) SendMessage(m proto.Message) {
 		slog.Error("Failed to send message", logging.Type(m), logging.Error(err))
 		return
 	}
-	a.logger.Debug("Sending to network", "peer", a.id, "data", proto.B64Bytes(b))
+	if a.logger.Enabled(context.Background(), slog.LevelDebug) {
+		a.logger.Debug("Sending to network", slog.Any("peer", a.id), logging.Data(b))
+	}
 
 	select {
 	case a.remote.ToCh <- b: