Start moving things to structured logging (#2527)

pkg/sfu/connectionquality/scorer.go

@@ -23,6 +23,7 @@ import (
 	"github.com/livekit/protocol/livekit"
 	"github.com/livekit/protocol/logger"
 	"github.com/livekit/protocol/utils"
+	"go.uber.org/zap/zapcore"
 )
 
 const (
@@ -159,6 +160,23 @@ func (w *windowStat) String() string {
 	)
 }
 
+func (w *windowStat) MarshalLogObject(e zapcore.ObjectEncoder) error {
+	if w == nil {
+		return nil
+	}
+
+	e.AddTime("startedAt", w.startedAt)
+	e.AddString("duration", w.duration.String())
+	e.AddUint32("packetsExpected", w.packetsExpected)
+	e.AddUint32("packetsLost", w.packetsLost)
+	e.AddUint32("packetsMissing", w.packetsMissing)
+	e.AddUint32("packetsOutOfOrder", w.packetsOutOfOrder)
+	e.AddUint64("bytes", w.bytes)
+	e.AddUint32("rttMax", w.rttMax)
+	e.AddFloat64("jitterMax", w.jitterMax)
+	return nil
+}
+
 // ------------------------------------------
 
 type qualityScorerParams struct {

pkg/sfu/downtrack.go

@@ -1211,7 +1211,7 @@ func (d *DownTrack) ProvisionalAllocateGetCooperativeTransition(allowOvershoot b
 	transition, availableLayers, brs := d.forwarder.ProvisionalAllocateGetCooperativeTransition(allowOvershoot)
 	d.params.Logger.Debugw(
 		"stream: cooperative transition",
-		"transition", transition,
+		"transition", &transition,
 		"availableLayers", availableLayers,
 		"bitrates", brs,
 	)
@@ -1222,7 +1222,7 @@ func (d *DownTrack) ProvisionalAllocateGetBestWeightedTransition() VideoTransiti
 	transition, availableLayers, brs := d.forwarder.ProvisionalAllocateGetBestWeightedTransition()
 	d.params.Logger.Debugw(
 		"stream: best weighted transition",
-		"transition", transition,
+		"transition", &transition,
 		"availableLayers", availableLayers,
 		"bitrates", brs,
 	)

pkg/sfu/forwarder.go

@@ -25,6 +25,7 @@ import (
 
 	"github.com/pion/rtp"
 	"github.com/pion/webrtc/v3"
+	"go.uber.org/zap/zapcore"
 
 	"github.com/livekit/protocol/logger"
 
@@ -92,7 +93,7 @@ type VideoAllocation struct {
 	DistanceToDesired   float64
 }
 
-func (v VideoAllocation) String() string {
+func (v *VideoAllocation) String() string {
 	return fmt.Sprintf("VideoAllocation{pause: %s, def: %+v, bwr: %d, del: %d, bwn: %d, rates: %+v, target: %s, req: %d, max: %s, dist: %0.2f}",
 		v.PauseReason,
 		v.IsDeficient,
@@ -107,6 +108,24 @@ func (v VideoAllocation) String() string {
 	)
 }
 
+func (v *VideoAllocation) MarshalLogObject(e zapcore.ObjectEncoder) error {
+	if v == nil {
+		return nil
+	}
+
+	e.AddString("PauseReason", v.PauseReason.String())
+	e.AddBool("IsDeficient", v.IsDeficient)
+	e.AddInt64("BandwidthRquested", v.BandwidthRequested)
+	e.AddInt64("BandwidthDelta", v.BandwidthDelta)
+	e.AddInt64("BandwidthNeeded", v.BandwidthNeeded)
+	e.AddReflected("Bitrates", v.Bitrates)
+	e.AddReflected("TargetLayer", v.TargetLayer)
+	e.AddInt32("RequestLayerSpatial", v.RequestLayerSpatial)
+	e.AddReflected("MaxLayer", v.MaxLayer)
+	e.AddFloat64("DistanceToDesired", v.DistanceToDesired)
+	return nil
+}
+
 var (
 	VideoAllocationDefault = VideoAllocation{
 		PauseReason:         VideoPauseReasonFeedDry, // start with no feed till feed is seen
@@ -137,10 +156,21 @@ type VideoTransition struct {
 	BandwidthDelta int64
 }
 
-func (v VideoTransition) String() string {
+func (v *VideoTransition) String() string {
 	return fmt.Sprintf("VideoTransition{from: %s, to: %s, del: %d}", v.From, v.To, v.BandwidthDelta)
 }
 
+func (v *VideoTransition) MarshalLogObject(e zapcore.ObjectEncoder) error {
+	if v == nil {
+		return nil
+	}
+
+	e.AddReflected("From", v.From)
+	e.AddReflected("To", v.To)
+	e.AddInt64("BandwidthDelta", v.BandwidthDelta)
+	return nil
+}
+
 // -------------------------------------------------------------------
 
 type TranslationParams struct {
@@ -1359,7 +1389,7 @@ func (f *Forwarder) updateAllocation(alloc VideoAllocation, reason string) Video
 		alloc.PauseReason != f.lastAllocation.PauseReason ||
 		alloc.TargetLayer != f.lastAllocation.TargetLayer ||
 		alloc.RequestLayerSpatial != f.lastAllocation.RequestLayerSpatial {
-		f.logger.Debugw(fmt.Sprintf("stream allocation: %s", reason), "allocation", alloc)
+		f.logger.Debugw(fmt.Sprintf("stream allocation: %s", reason), "allocation", &alloc)
 	}
 	f.lastAllocation = alloc