From 42a8ab232de194cc42198b570e40ba9998e5b0ee Mon Sep 17 00:00:00 2001 From: cnderrauber Date: Thu, 10 Aug 2023 23:06:09 +0800 Subject: [PATCH 01/21] Never use dd tracker for non-svc codec (#1952) --- pkg/sfu/receiver.go | 10 ++++++---- 1 file changed, 6 insertions(+), 4 deletions(-) diff --git a/pkg/sfu/receiver.go b/pkg/sfu/receiver.go index e24d8b1b0..69d3d1265 100644 --- a/pkg/sfu/receiver.go +++ b/pkg/sfu/receiver.go @@ -231,10 +231,12 @@ func NewWebRTCReceiver( }) w.connectionStats.Start(w.trackInfo) - for _, ext := range receiver.GetParameters().HeaderExtensions { - if ext.URI == dd.ExtensionURI { - w.streamTrackerManager.AddDependencyDescriptorTrackers() - break + if w.isSVC { + for _, ext := range receiver.GetParameters().HeaderExtensions { + if ext.URI == dd.ExtensionURI { + w.streamTrackerManager.AddDependencyDescriptorTrackers() + break + } } } From ae29d05ec92c78f63e4281e5f7cf81213f869bcb Mon Sep 17 00:00:00 2001 From: Raja Subramanian Date: Thu, 10 Aug 2023 23:02:10 +0530 Subject: [PATCH 02/21] Check RTPSender is valid (#1953) On a quick Bind + Unbind, the go routine to get parameters running late could encounter a nil sender. Check for it. --- pkg/sfu/downtrack.go | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/pkg/sfu/downtrack.go b/pkg/sfu/downtrack.go index ff287ae20..eceb854fa 100644 --- a/pkg/sfu/downtrack.go +++ b/pkg/sfu/downtrack.go @@ -408,9 +408,11 @@ func (d *DownTrack) Bind(t webrtc.TrackLocalContext) (webrtc.RTPCodecParameters, // Bind is called under RTPSender.mu lock, call the RTPSender.GetParameters in goroutine to avoid deadlock go func() { if tr := d.transceiver.Load(); tr != nil { - extensions := tr.Sender().GetParameters().HeaderExtensions - d.params.Logger.Debugw("negotiated downtrack extensions", "extensions", extensions) - d.SetRTPHeaderExtensions(extensions) + if sender := tr.Sender(); sender != nil { + extensions := sender.GetParameters().HeaderExtensions + d.params.Logger.Debugw("negotiated downtrack extensions", "extensions", extensions) + d.SetRTPHeaderExtensions(extensions) + } } }() From 387faf2718bcf58322f6f7fdfcd6312db9bc840c Mon Sep 17 00:00:00 2001 From: David Zhao Date: Thu, 10 Aug 2023 18:50:19 -0700 Subject: [PATCH 03/21] Demote removing subscribers for MIME (#1954) --- pkg/rtc/mediatrackreceiver.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pkg/rtc/mediatrackreceiver.go b/pkg/rtc/mediatrackreceiver.go index a89bd2c8a..692885a25 100644 --- a/pkg/rtc/mediatrackreceiver.go +++ b/pkg/rtc/mediatrackreceiver.go @@ -520,7 +520,7 @@ func (t *MediaTrackReceiver) RemoveSubscriber(subscriberID livekit.ParticipantID } func (t *MediaTrackReceiver) removeAllSubscribersForMime(mime string, willBeResumed bool) { - t.params.Logger.Infow("removing all subscribers for mime", "mime", mime) + t.params.Logger.Debugw("removing all subscribers for mime", "mime", mime) for _, subscriberID := range t.MediaTrackSubscriptions.GetAllSubscribersForMime(mime) { t.RemoveSubscriber(subscriberID, willBeResumed) } From 19b84207a16a69de3979026ead5e87e7595654e4 Mon Sep 17 00:00:00 2001 From: Raja Subramanian Date: Fri, 11 Aug 2023 09:43:12 +0530 Subject: [PATCH 04/21] Use 32-bit ts for first packet adjustment. (#1955) * Use 32-bit ts for first packet adjustment. Otherwise, a new subscriber on a long running sees a huge difference if the publisher side has rolled over. As this happens only in the first two minutes of a track's lifecycle it is fine to not consider rollover. * log RTP in anachronous report --- pkg/sfu/buffer/rtpstats.go | 19 +++++++++++++------ 1 file changed, 13 insertions(+), 6 deletions(-) diff --git a/pkg/sfu/buffer/rtpstats.go b/pkg/sfu/buffer/rtpstats.go index 0eed03660..f73e1676b 100644 --- a/pkg/sfu/buffer/rtpstats.go +++ b/pkg/sfu/buffer/rtpstats.go @@ -771,11 +771,11 @@ func (r *RTPStats) MaybeAdjustFirstPacketTime(srData *RTCPSenderReportData) { defer r.lock.Unlock() if srData != nil { - r.maybeAdjustFirstPacketTime(srData.RTPTimestampExt) + r.maybeAdjustFirstPacketTime(srData.RTPTimestamp) } } -func (r *RTPStats) maybeAdjustFirstPacketTime(extTS uint64) { +func (r *RTPStats) maybeAdjustFirstPacketTime(ts uint32) { if time.Since(r.startTime) > firstPacketTimeAdjustWindow { return } @@ -786,7 +786,12 @@ func (r *RTPStats) maybeAdjustFirstPacketTime(extTS uint64) { // abnormal delay (maybe due to pacing or maybe due to queuing // in some network element along the way), push back first time // to an earlier instance. - samplesDuration := time.Duration(float64(extTS-r.extStartTS) / float64(r.params.ClockRate) * float64(time.Second)) + samplesDiff := int32(ts - uint32(r.extStartTS)) + if samplesDiff < 0 { + // out-of-order, skip + return + } + samplesDuration := time.Duration(float64(samplesDiff) / float64(r.params.ClockRate) * float64(time.Second)) firstTime := time.Now().Add(-samplesDuration) if firstTime.Before(r.firstTime) { r.logger.Infow( @@ -814,8 +819,10 @@ func (r *RTPStats) SetRtcpSenderReportData(srData *RTCPSenderReportData) { if r.srNewest != nil && r.srNewest.NTPTimestamp > srData.NTPTimestamp { r.logger.Infow( "received anachronous sender report", - "current", srData.NTPTimestamp.Time(), - "last", r.srNewest.NTPTimestamp.Time(), + "currentNTP", srData.NTPTimestamp.Time(), + "currentRTP", srData.RTPTimestamp, + "lastNTP", r.srNewest.NTPTimestamp.Time(), + "lastRTP", r.srNewest.RTPTimestamp, ) return } @@ -831,7 +838,7 @@ func (r *RTPStats) SetRtcpSenderReportData(srData *RTCPSenderReportData) { srDataCopy := *srData srDataCopy.RTPTimestampExt = uint64(srDataCopy.RTPTimestamp) + cycles - r.maybeAdjustFirstPacketTime(srDataCopy.RTPTimestampExt) + r.maybeAdjustFirstPacketTime(srDataCopy.RTPTimestamp) // monitor and log RTP timestamp anomalies var ntpDiffSinceLast time.Duration From 51650ea3018d3d613606ec4b94203d4a91a11c4f Mon Sep 17 00:00:00 2001 From: Raja Subramanian Date: Fri, 11 Aug 2023 10:17:13 +0530 Subject: [PATCH 05/21] Use refTS if ahead. (#1956) As expectedTS is tied to first packet and first packet adjustment may not have happened, refTS being ahead is not a bad thing. In one example, - first packet was late - a layer switch happened around 110ms later - in that time, 190ms worth of media was forwarded - but first packet adjustment did not happen yet - so at that layer switch, expected was behind - choosing ref at that switch is the right thing --- pkg/sfu/forwarder.go | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/pkg/sfu/forwarder.go b/pkg/sfu/forwarder.go index 74cb87de8..5edbcef57 100644 --- a/pkg/sfu/forwarder.go +++ b/pkg/sfu/forwarder.go @@ -1563,10 +1563,8 @@ func (f *Forwarder) processSourceSwitch(extPkt *buffer.ExtPacket, layer int32) e diffSeconds = float64(int32(expectedTS-refTS)) / float64(f.codec.ClockRate) if diffSeconds < 0.0 && math.Abs(diffSeconds) > SwitchAheadThresholdSeconds { logTransition("layer switch, reference too far ahead", expectedTS, refTS, lastTS, diffSeconds) - nextTS = expectedTS - } else { - nextTS = refTS } + nextTS = refTS } } From 114888e7c7409feb8536e70a3c312a973f2e5895 Mon Sep 17 00:00:00 2001 From: Raja Subramanian Date: Fri, 11 Aug 2023 10:50:11 +0530 Subject: [PATCH 06/21] log next sequence number also, easier to check layer switches (#1957) --- pkg/sfu/forwarder.go | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/pkg/sfu/forwarder.go b/pkg/sfu/forwarder.go index 5edbcef57..0f72f67aa 100644 --- a/pkg/sfu/forwarder.go +++ b/pkg/sfu/forwarder.go @@ -1465,7 +1465,8 @@ func (f *Forwarder) processSourceSwitch(extPkt *buffer.ExtPacket, layer int32) e // 3. expectedTS -> expected timestamp of this packet calculated based on elapsed time since first packet // Ideally, refTS and expectedTS should be very close and lastTS should be before both of those. // But, cases like muting/unmuting, clock vagaries, pacing, etc. make them not satisfy those conditions always. - lastTS := f.rtpMunger.GetLast().LastTS + rtpMungerState := f.rtpMunger.GetLast() + lastTS := rtpMungerState.LastTS refTS := lastTS expectedTS := lastTS switchingAt := time.Now() @@ -1583,7 +1584,8 @@ func (f *Forwarder) processSourceSwitch(extPkt *buffer.ExtPacket, layer int32) e "referenceLayerSpatial", f.referenceLayerSpatial, "expectedTS", expectedTS, "nextTS", nextTS, - "jump", nextTS-lastTS, + "tsJump", nextTS-lastTS, + "nextSN", rtpMungerState.LastSN+1, ) f.rtpMunger.UpdateSnTsOffsets(extPkt, 1, nextTS-lastTS) From 5c0a4beb61ba11b4801262e52b9360e5cba7bcd1 Mon Sep 17 00:00:00 2001 From: Raja Subramanian Date: Fri, 11 Aug 2023 13:03:10 +0530 Subject: [PATCH 07/21] Log more about layer offset. (#1959) Seeing a good chunk of logs using default offset. And it is concentrated heavily on few tracks. Logging more to understand this better before potentially demoting this log. --- pkg/sfu/buffer/rtpstats.go | 4 ++-- pkg/sfu/streamtrackermanager.go | 10 +++++++++- 2 files changed, 11 insertions(+), 3 deletions(-) diff --git a/pkg/sfu/buffer/rtpstats.go b/pkg/sfu/buffer/rtpstats.go index f73e1676b..e792c819c 100644 --- a/pkg/sfu/buffer/rtpstats.go +++ b/pkg/sfu/buffer/rtpstats.go @@ -819,9 +819,9 @@ func (r *RTPStats) SetRtcpSenderReportData(srData *RTCPSenderReportData) { if r.srNewest != nil && r.srNewest.NTPTimestamp > srData.NTPTimestamp { r.logger.Infow( "received anachronous sender report", - "currentNTP", srData.NTPTimestamp.Time(), + "currentNTP", srData.NTPTimestamp.Time().String(), "currentRTP", srData.RTPTimestamp, - "lastNTP", r.srNewest.NTPTimestamp.Time(), + "lastNTP", r.srNewest.NTPTimestamp.Time().String(), "lastRTP", r.srNewest.RTPTimestamp, ) return diff --git a/pkg/sfu/streamtrackermanager.go b/pkg/sfu/streamtrackermanager.go index 30ba98322..8f3c45190 100644 --- a/pkg/sfu/streamtrackermanager.go +++ b/pkg/sfu/streamtrackermanager.go @@ -571,7 +571,15 @@ func (s *StreamTrackerManager) updateLayerOffsetLocked(ref, other int32) { // use minimal offset to indicate value availability in the extremely unlikely case of // both layers using the same timestamp if offset == 0 { - s.logger.Infow("using default offset", "ref", ref, "other", other) + s.logger.Infow( + "using default offset", + "ref", ref, + "refNTP", srRef.NTPTimestamp.Time().String(), + "refRTP", srRef.RTPTimestamp, + "other", other, + "otherNTP", srOther.NTPTimestamp.Time().String(), + "otherRTP", srOther.RTPTimestamp, + ) offset = 1 } From ce1fde451ce3388617c9561de4c1f7bbf36c39f2 Mon Sep 17 00:00:00 2001 From: Raja Subramanian Date: Fri, 11 Aug 2023 17:22:56 +0530 Subject: [PATCH 08/21] Get next higher using bit rate. (#1960) --- pkg/sfu/forwarder.go | 5 ++++- pkg/sfu/streamallocator/streamallocator.go | 16 ++++++++-------- 2 files changed, 12 insertions(+), 9 deletions(-) diff --git a/pkg/sfu/forwarder.go b/pkg/sfu/forwarder.go index 0f72f67aa..696c19817 100644 --- a/pkg/sfu/forwarder.go +++ b/pkg/sfu/forwarder.go @@ -1220,7 +1220,10 @@ func (f *Forwarder) GetNextHigherTransition(brs Bitrates, allowOvershoot bool) ( for s := minSpatial; s <= maxSpatial; s++ { for t := minTemporal; t <= maxTemporal; t++ { bandwidthRequested := brs[s][t] - if bandwidthRequested == 0 { + // traverse till finding a layer requiring more bits. + // NOTE: it possible that higher temporal layer of lower spatial layer + // could use more bits than lower temporal layer of higher spatial layer. + if bandwidthRequested == 0 || bandwidthRequested < alreadyAllocated { continue } diff --git a/pkg/sfu/streamallocator/streamallocator.go b/pkg/sfu/streamallocator/streamallocator.go index 48d7eb14c..4b0a61015 100644 --- a/pkg/sfu/streamallocator/streamallocator.go +++ b/pkg/sfu/streamallocator/streamallocator.go @@ -852,24 +852,19 @@ func (s *StreamAllocator) allocateTrack(track *Track) { // // For both cases, do // a. Find cooperative transition from track that needs allocation. - // b. If track is currently streaming at minimum, do not do anything. - // c. If track is giving back bits, apply the transition and use bits given + // b. If track is giving back bits, apply the transition and use bits given // back to boost any deficient track(s). // // If track needs more bits, i.e. upward transition (may need resume or higher layer subscription), // a. Try to allocate using existing headroom. This can be tried to get the best // possible fit for the available headroom. // b. If there is not enough headroom to allocate anything, ask for best offer from - // other tracks that are currently streaming and try to use it. + // other tracks that are currently streaming and try to use it. This is done only if the + // track needing change is not currently streaming, i. e. it has to be resumed. // track.ProvisionalAllocatePrepare() transition := track.ProvisionalAllocateGetCooperativeTransition(FlagAllowOvershootWhileDeficient) - // track is currently streaming at minimum - if transition.BandwidthDelta == 0 { - return - } - // downgrade, giving back bits if transition.From.GreaterThan(transition.To) { allocation := track.ProvisionalAllocateCommit() @@ -928,6 +923,11 @@ func (s *StreamAllocator) allocateTrack(track *Track) { transition = track.ProvisionalAllocateGetCooperativeTransition(FlagAllowOvershootWhileDeficient) // get transition again to reset above allocation attempt using available headroom } + // track is currently streaming at minimum + if transition.BandwidthDelta == 0 { + return + } + // if there is not enough headroom, try to redistribute starting with tracks that are closest to their desired. bandwidthAcquired := int64(0) var contributingTracks []*Track From d5a180d16751b2368f90f17d8b6e7daa8f53e9a3 Mon Sep 17 00:00:00 2001 From: cnderrauber Date: Mon, 14 Aug 2023 10:35:09 +0800 Subject: [PATCH 09/21] Add option to advertise external ip only (#1962) --- go.mod | 2 +- go.sum | 4 ++-- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/go.mod b/go.mod index e17bd663d..6f266f615 100644 --- a/go.mod +++ b/go.mod @@ -17,7 +17,7 @@ require ( github.com/hashicorp/golang-lru/v2 v2.0.5 github.com/jxskiss/base62 v1.1.0 github.com/livekit/mageutil v0.0.0-20230125210925-54e8a70427c1 - github.com/livekit/mediatransportutil v0.0.0-20230716190407-fc4944cbc33a + github.com/livekit/mediatransportutil v0.0.0-20230814022007-baa55469800f github.com/livekit/protocol v1.6.0 github.com/livekit/psrpc v0.3.2 github.com/mackerelio/go-osstat v0.2.4 diff --git a/go.sum b/go.sum index 9adab1ff4..d4767af68 100644 --- a/go.sum +++ b/go.sum @@ -122,8 +122,8 @@ github.com/lithammer/shortuuid/v4 v4.0.0 h1:QRbbVkfgNippHOS8PXDkti4NaWeyYfcBTHtw github.com/lithammer/shortuuid/v4 v4.0.0/go.mod h1:Zs8puNcrvf2rV9rTH51ZLLcj7ZXqQI3lv67aw4KiB1Y= github.com/livekit/mageutil v0.0.0-20230125210925-54e8a70427c1 h1:jm09419p0lqTkDaKb5iXdynYrzB84ErPPO4LbRASk58= github.com/livekit/mageutil v0.0.0-20230125210925-54e8a70427c1/go.mod h1:Rs3MhFwutWhGwmY1VQsygw28z5bWcnEYmS1OG9OxjOQ= -github.com/livekit/mediatransportutil v0.0.0-20230716190407-fc4944cbc33a h1:JWpPHcMFuw0fP4swE89CfMgeUXiSN5IKvCJL/5HLI3A= -github.com/livekit/mediatransportutil v0.0.0-20230716190407-fc4944cbc33a/go.mod h1:xirUXW8xnLGmfCwUeAv/nj1VGo1OO1BmgxrYP7jK/14= +github.com/livekit/mediatransportutil v0.0.0-20230814022007-baa55469800f h1:yx+wHBjT/0+nOJsosQzYH+SWMR8AZSqDs1m0AA0+qSs= +github.com/livekit/mediatransportutil v0.0.0-20230814022007-baa55469800f/go.mod h1:xirUXW8xnLGmfCwUeAv/nj1VGo1OO1BmgxrYP7jK/14= github.com/livekit/protocol v1.6.0 h1:19S+vFZqnivKIOpyR3DEK/mSaykQ3UEf7H2G/mBOE54= github.com/livekit/protocol v1.6.0/go.mod h1:SUS9foM1xBzw/AFrgTJuFX/oSuwlnIbHmpdiPdCvwEM= github.com/livekit/psrpc v0.3.2 h1:eAaJhASme33gtoBhCRLH9jsnWcdm1tHWf0WzaDk56ew= From 83111eee48f300188e0e74a0b34e987857a8f026 Mon Sep 17 00:00:00 2001 From: cnderrauber Date: Mon, 14 Aug 2023 11:53:01 +0800 Subject: [PATCH 10/21] Don't filter out ipv6 address (#1963) --- go.mod | 2 +- go.sum | 4 ++-- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/go.mod b/go.mod index 6f266f615..985cdc553 100644 --- a/go.mod +++ b/go.mod @@ -17,7 +17,7 @@ require ( github.com/hashicorp/golang-lru/v2 v2.0.5 github.com/jxskiss/base62 v1.1.0 github.com/livekit/mageutil v0.0.0-20230125210925-54e8a70427c1 - github.com/livekit/mediatransportutil v0.0.0-20230814022007-baa55469800f + github.com/livekit/mediatransportutil v0.0.0-20230814030822-8d5de0008b08 github.com/livekit/protocol v1.6.0 github.com/livekit/psrpc v0.3.2 github.com/mackerelio/go-osstat v0.2.4 diff --git a/go.sum b/go.sum index d4767af68..51d44ec2b 100644 --- a/go.sum +++ b/go.sum @@ -122,8 +122,8 @@ github.com/lithammer/shortuuid/v4 v4.0.0 h1:QRbbVkfgNippHOS8PXDkti4NaWeyYfcBTHtw github.com/lithammer/shortuuid/v4 v4.0.0/go.mod h1:Zs8puNcrvf2rV9rTH51ZLLcj7ZXqQI3lv67aw4KiB1Y= github.com/livekit/mageutil v0.0.0-20230125210925-54e8a70427c1 h1:jm09419p0lqTkDaKb5iXdynYrzB84ErPPO4LbRASk58= github.com/livekit/mageutil v0.0.0-20230125210925-54e8a70427c1/go.mod h1:Rs3MhFwutWhGwmY1VQsygw28z5bWcnEYmS1OG9OxjOQ= -github.com/livekit/mediatransportutil v0.0.0-20230814022007-baa55469800f h1:yx+wHBjT/0+nOJsosQzYH+SWMR8AZSqDs1m0AA0+qSs= -github.com/livekit/mediatransportutil v0.0.0-20230814022007-baa55469800f/go.mod h1:xirUXW8xnLGmfCwUeAv/nj1VGo1OO1BmgxrYP7jK/14= +github.com/livekit/mediatransportutil v0.0.0-20230814030822-8d5de0008b08 h1:e0qwVjrtzmADgNZpdgSJgyhlF6BgrHkpdnkONL8pLrw= +github.com/livekit/mediatransportutil v0.0.0-20230814030822-8d5de0008b08/go.mod h1:xirUXW8xnLGmfCwUeAv/nj1VGo1OO1BmgxrYP7jK/14= github.com/livekit/protocol v1.6.0 h1:19S+vFZqnivKIOpyR3DEK/mSaykQ3UEf7H2G/mBOE54= github.com/livekit/protocol v1.6.0/go.mod h1:SUS9foM1xBzw/AFrgTJuFX/oSuwlnIbHmpdiPdCvwEM= github.com/livekit/psrpc v0.3.2 h1:eAaJhASme33gtoBhCRLH9jsnWcdm1tHWf0WzaDk56ew= From 77c8e824735b340065981fae45add6cfb18655c6 Mon Sep 17 00:00:00 2001 From: Raja Subramanian Date: Mon, 14 Aug 2023 23:50:01 +0530 Subject: [PATCH 11/21] log adjustment for first packet (#1965) --- pkg/sfu/buffer/rtpstats.go | 10 ++++++++-- 1 file changed, 8 insertions(+), 2 deletions(-) diff --git a/pkg/sfu/buffer/rtpstats.go b/pkg/sfu/buffer/rtpstats.go index e792c819c..1d0bdd2b8 100644 --- a/pkg/sfu/buffer/rtpstats.go +++ b/pkg/sfu/buffer/rtpstats.go @@ -794,13 +794,19 @@ func (r *RTPStats) maybeAdjustFirstPacketTime(ts uint32) { samplesDuration := time.Duration(float64(samplesDiff) / float64(r.params.ClockRate) * float64(time.Second)) firstTime := time.Now().Add(-samplesDuration) if firstTime.Before(r.firstTime) { - r.logger.Infow( + r.logger.Debugw( "adjusting first packet time", "before", r.firstTime.String(), "after", firstTime.String(), ) if r.firstTime.Sub(firstTime) > firstPacketTimeAdjustThreshold { - r.logger.Infow("first packet time adjustment too big, ignoring", "adjustment", r.firstTime.Sub(firstTime)) + r.logger.Infow("first packet time adjustment too big, ignoring", + "adjustment", r.firstTime.Sub(firstTime), + "before", r.firstTime.String(), + "after", firstTime.String(), + "ts", ts, + "extStartTS", r.extStartTS, + ) } else { r.firstTime = firstTime } From 221be0cb45ae47dfb665f97cc61c7d81b207b84c Mon Sep 17 00:00:00 2001 From: Raja Subramanian Date: Tue, 15 Aug 2023 15:40:30 +0530 Subject: [PATCH 12/21] mediatransportutil update (#1966) --- go.mod | 2 +- go.sum | 4 ++-- pkg/sfu/redreceiver.go | 2 +- 3 files changed, 4 insertions(+), 4 deletions(-) diff --git a/go.mod b/go.mod index 985cdc553..096ce3da3 100644 --- a/go.mod +++ b/go.mod @@ -17,7 +17,7 @@ require ( github.com/hashicorp/golang-lru/v2 v2.0.5 github.com/jxskiss/base62 v1.1.0 github.com/livekit/mageutil v0.0.0-20230125210925-54e8a70427c1 - github.com/livekit/mediatransportutil v0.0.0-20230814030822-8d5de0008b08 + github.com/livekit/mediatransportutil v0.0.0-20230815100155-96164dbcfd8c github.com/livekit/protocol v1.6.0 github.com/livekit/psrpc v0.3.2 github.com/mackerelio/go-osstat v0.2.4 diff --git a/go.sum b/go.sum index 51d44ec2b..4568d6d10 100644 --- a/go.sum +++ b/go.sum @@ -122,8 +122,8 @@ github.com/lithammer/shortuuid/v4 v4.0.0 h1:QRbbVkfgNippHOS8PXDkti4NaWeyYfcBTHtw github.com/lithammer/shortuuid/v4 v4.0.0/go.mod h1:Zs8puNcrvf2rV9rTH51ZLLcj7ZXqQI3lv67aw4KiB1Y= github.com/livekit/mageutil v0.0.0-20230125210925-54e8a70427c1 h1:jm09419p0lqTkDaKb5iXdynYrzB84ErPPO4LbRASk58= github.com/livekit/mageutil v0.0.0-20230125210925-54e8a70427c1/go.mod h1:Rs3MhFwutWhGwmY1VQsygw28z5bWcnEYmS1OG9OxjOQ= -github.com/livekit/mediatransportutil v0.0.0-20230814030822-8d5de0008b08 h1:e0qwVjrtzmADgNZpdgSJgyhlF6BgrHkpdnkONL8pLrw= -github.com/livekit/mediatransportutil v0.0.0-20230814030822-8d5de0008b08/go.mod h1:xirUXW8xnLGmfCwUeAv/nj1VGo1OO1BmgxrYP7jK/14= +github.com/livekit/mediatransportutil v0.0.0-20230815100155-96164dbcfd8c h1:4udPqCusH93MK/7q8ZfDqcLJHGoQeKKsMi5b+/BpQvk= +github.com/livekit/mediatransportutil v0.0.0-20230815100155-96164dbcfd8c/go.mod h1:xirUXW8xnLGmfCwUeAv/nj1VGo1OO1BmgxrYP7jK/14= github.com/livekit/protocol v1.6.0 h1:19S+vFZqnivKIOpyR3DEK/mSaykQ3UEf7H2G/mBOE54= github.com/livekit/protocol v1.6.0/go.mod h1:SUS9foM1xBzw/AFrgTJuFX/oSuwlnIbHmpdiPdCvwEM= github.com/livekit/psrpc v0.3.2 h1:eAaJhASme33gtoBhCRLH9jsnWcdm1tHWf0WzaDk56ew= diff --git a/pkg/sfu/redreceiver.go b/pkg/sfu/redreceiver.go index 57cf49e8b..9254be438 100644 --- a/pkg/sfu/redreceiver.go +++ b/pkg/sfu/redreceiver.go @@ -114,7 +114,7 @@ func (r *RedReceiver) Close() { func (r *RedReceiver) ReadRTP(buf []byte, layer uint8, sn uint16) (int, error) { // red encoding don't support nack - return 0, bucket.ErrPacketNotFound + return 0, bucket.ErrPacketMismatch } func (r *RedReceiver) encodeRedForPrimary(pkt *rtp.Packet, redPayload []byte) (int, error) { From 96fa2f896b40f2d6bf34024e22d18c45598cc832 Mon Sep 17 00:00:00 2001 From: Raja Subramanian Date: Tue, 15 Aug 2023 23:09:45 +0530 Subject: [PATCH 13/21] Set 32-bit RTP timestamp properly after repair. (#1968) --- pkg/sfu/buffer/rtpstats.go | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/pkg/sfu/buffer/rtpstats.go b/pkg/sfu/buffer/rtpstats.go index 1d0bdd2b8..1a556c3d0 100644 --- a/pkg/sfu/buffer/rtpstats.go +++ b/pkg/sfu/buffer/rtpstats.go @@ -965,7 +965,7 @@ func (r *RTPStats) GetRtcpSenderReport(ssrc uint32, calculatedClockRate uint32) nowRTPExtUsingRate = r.extStartTS + uint64(float64(calculatedClockRate)*timeSinceFirst.Seconds()) if nowRTPExtUsingRate > nowRTPExt { nowRTPExt = nowRTPExtUsingRate - nowRTP = uint32(nowRTPExtUsingRate) + nowRTP = uint32(nowRTPExt) } } @@ -992,6 +992,7 @@ func (r *RTPStats) GetRtcpSenderReport(ssrc uint32, calculatedClockRate uint32) ) ntpDiffSinceLast := nowNTP.Time().Sub(r.srNewest.NTPTimestamp.Time()) nowRTPExt = r.srNewest.RTPTimestampExt + uint64(ntpDiffSinceLast.Seconds()*float64(r.params.ClockRate)) + nowRTP = uint32(nowRTPExt) } // monitor and log RTP timestamp anomalies From 13b1b4808fdfb6838a6c38462f27b5c1463258fd Mon Sep 17 00:00:00 2001 From: David Zhao Date: Tue, 15 Aug 2023 17:30:26 -0700 Subject: [PATCH 14/21] Fix race condition causing new participants to have stale room metadata (#1969) If room metadata is changed in between when a participant is joining and when they've became active, that participant will not have the latest room metadata. --- pkg/rtc/room.go | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/pkg/rtc/room.go b/pkg/rtc/room.go index f153d27ee..7d8a12a03 100644 --- a/pkg/rtc/room.go +++ b/pkg/rtc/room.go @@ -740,9 +740,7 @@ func (r *Room) sendRoomUpdate() { roomInfo := r.ToProto() // Send update to participants for _, p := range r.GetParticipants() { - // new participants receive the update as part of JoinResponse - // skip inactive participants - if p.State() != livekit.ParticipantInfo_ACTIVE { + if !p.IsReady() { continue } From 8b3deafbd47d811d31b20374a7196cee672fdaeb Mon Sep 17 00:00:00 2001 From: "renovate[bot]" <29139614+renovate[bot]@users.noreply.github.com> Date: Tue, 15 Aug 2023 17:30:49 -0700 Subject: [PATCH 15/21] Update golang.org/x/exp digest to 89c5cff (#1961) Generated by renovateBot Co-authored-by: renovate[bot] <29139614+renovate[bot]@users.noreply.github.com> --- go.mod | 2 +- go.sum | 4 ++-- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/go.mod b/go.mod index 096ce3da3..b6db038c2 100644 --- a/go.mod +++ b/go.mod @@ -45,7 +45,7 @@ require ( github.com/urfave/cli/v2 v2.25.7 github.com/urfave/negroni/v3 v3.0.0 go.uber.org/atomic v1.11.0 - golang.org/x/exp v0.0.0-20230810033253-352e893a4cad + golang.org/x/exp v0.0.0-20230811145659-89c5cff77bcb golang.org/x/sync v0.3.0 google.golang.org/protobuf v1.31.0 gopkg.in/yaml.v3 v3.0.1 diff --git a/go.sum b/go.sum index 4568d6d10..ef0468a16 100644 --- a/go.sum +++ b/go.sum @@ -293,8 +293,8 @@ golang.org/x/crypto v0.8.0/go.mod h1:mRqEX+O9/h5TFCrQhkgjo2yKi0yYA+9ecGkdQoHrywE golang.org/x/crypto v0.10.0/go.mod h1:o4eNf7Ede1fv+hwOwZsTHl9EsPFO6q6ZvYR8vYfY45I= golang.org/x/crypto v0.11.0 h1:6Ewdq3tDic1mg5xRO4milcWCfMVQhI4NkqWWvqejpuA= golang.org/x/crypto v0.11.0/go.mod h1:xgJhtzW8F9jGdVFWZESrid1U1bjeNy4zgy5cRr/CIio= -golang.org/x/exp v0.0.0-20230810033253-352e893a4cad h1:g0bG7Z4uG+OgH2QDODnjp6ggkk1bJDsINcuWmJN1iJU= -golang.org/x/exp v0.0.0-20230810033253-352e893a4cad/go.mod h1:FXUEEKJgO7OQYeo8N01OfiKP8RXMtf6e8aTskBGqWdc= +golang.org/x/exp v0.0.0-20230811145659-89c5cff77bcb h1:mIKbk8weKhSeLH2GmUTrvx8CjkyJmnU1wFmg59CUjFA= +golang.org/x/exp v0.0.0-20230811145659-89c5cff77bcb/go.mod h1:FXUEEKJgO7OQYeo8N01OfiKP8RXMtf6e8aTskBGqWdc= golang.org/x/mod v0.3.0/go.mod h1:s0Qsj1ACt9ePp/hMypM3fl4fZqREWJwdYDEqhRiZZUA= golang.org/x/mod v0.6.0-dev.0.20220419223038-86c51ed26bb4/go.mod h1:jJ57K6gSWd91VN4djpZkiMVwK6gcyfeH4XE8wZrZaV4= golang.org/x/mod v0.8.0/go.mod h1:iBbtSCu2XBx23ZKBPSOrRkjjQPZFPuis4dIYUhu/chs= From c0ea1b9ced1973ff84f417088610d5fb35f3c6ed Mon Sep 17 00:00:00 2001 From: Raja Subramanian Date: Wed, 16 Aug 2023 12:17:29 +0530 Subject: [PATCH 16/21] Remove warning for probe rate being too high. (#1970) Not super useful. It does happen a bunch of times especially at lower end of estimate where the next layer up is high. We have to probe anyway. Effects of large jumps have been mitigated by doing it for short time. --- pkg/sfu/streamallocator/streamallocator.go | 14 -------------- 1 file changed, 14 deletions(-) diff --git a/pkg/sfu/streamallocator/streamallocator.go b/pkg/sfu/streamallocator/streamallocator.go index 4b0a61015..6441714b2 100644 --- a/pkg/sfu/streamallocator/streamallocator.go +++ b/pkg/sfu/streamallocator/streamallocator.go @@ -1212,20 +1212,6 @@ func (s *StreamAllocator) newChannelObserverNonProbe() *ChannelObserver { func (s *StreamAllocator) initProbe(probeGoalDeltaBps int64) { expectedBandwidthUsage := s.getExpectedBandwidthUsage() - if float64(expectedBandwidthUsage) > 1.5*float64(s.committedChannelCapacity) { - // STREAM-ALLOCATOR-TODO-START - // Should probably skip probing if the expected usage is much higher than committed channel capacity. - // But, give that bandwidth estimate is volatile at times and can drop down to small values, - // not probing means streaming stuck in a well for long. - // Observe this and figure out if there is a threshold from practical use cases that can be used to - // skip probing safely - // STREAM-ALLOCATOR-TODO-END - s.params.Logger.Warnw( - "stream allocator: starting probe alarm", - fmt.Errorf("expected too high, expected: %d, committed: %d", expectedBandwidthUsage, s.committedChannelCapacity), - ) - } - probeClusterId, probeGoalBps := s.probeController.InitProbe(probeGoalDeltaBps, expectedBandwidthUsage) channelState := "" From 480edff4ac6002201cbd3c4b38b8d7ae8e9ad644 Mon Sep 17 00:00:00 2001 From: Raja Subramanian Date: Wed, 16 Aug 2023 13:52:01 +0530 Subject: [PATCH 17/21] Adjust TS and cycles when adjusting start. (#1971) * Adjust TS and cycles when adjusting start. Chasing some AddPacket errors across relay. Noticed that in one case the start/end sequence was flipped. There is a known issue of it happening with resync. Unclear if this instance was due to resync or not. The start was close to the edge (64513). So, thought maybe adjust at start and noticed that it needs to maybe increase cycle count if start is wrapping back. In this case, the start is 1000 before wrap point. So, may not be a wrap back issue, but addressing what I found anyway. * fix test --- pkg/sfu/buffer/rtpstats.go | 28 ++++++++++++++++++++++++---- pkg/sfu/buffer/rtpstats_test.go | 3 +++ pkg/sfu/utils/wraparound.go | 2 +- 3 files changed, 28 insertions(+), 5 deletions(-) diff --git a/pkg/sfu/buffer/rtpstats.go b/pkg/sfu/buffer/rtpstats.go index 1a556c3d0..8f2b54f7d 100644 --- a/pkg/sfu/buffer/rtpstats.go +++ b/pkg/sfu/buffer/rtpstats.go @@ -424,7 +424,7 @@ func (r *RTPStats) Update(rtph *rtp.Header, payloadSize int, paddingSize int, pa } // adjust start to account for out-of-order packets before a cycle completes - if !r.maybeAdjustStartSN(rtph, pktSize, hdrSize, payloadSize) { + if !r.maybeAdjustStart(rtph, pktSize, hdrSize, payloadSize) { if !r.isSnInfoLost(rtph.SequenceNumber) { r.bytesDuplicate += pktSize r.headerBytesDuplicate += hdrSize @@ -497,7 +497,7 @@ func (r *RTPStats) ResyncOnNextPacket() { r.resyncOnNextPacket = true } -func (r *RTPStats) maybeAdjustStartSN(rtph *rtp.Header, pktSize uint64, hdrSize uint64, payloadSize int) bool { +func (r *RTPStats) maybeAdjustStart(rtph *rtp.Header, pktSize uint64, hdrSize uint64, payloadSize int) bool { if (r.getExtHighestSN() - r.extStartSN + 1) >= (NumSequenceNumbers / 2) { return false } @@ -507,17 +507,37 @@ func (r *RTPStats) maybeAdjustStartSN(rtph *rtp.Header, pktSize uint64, hdrSize } r.packetsLost += uint32(uint16(r.extStartSN)-rtph.SequenceNumber) - 1 - beforeAdjust := r.extStartSN + snBeforeAdjust := r.extStartSN r.extStartSN = uint32(rtph.SequenceNumber) + if r.extStartSN > snBeforeAdjust { + // wrapping back + r.cycles++ + } r.setSnInfo(rtph.SequenceNumber, uint16(pktSize), uint16(hdrSize), uint16(payloadSize), rtph.Marker, true) for _, s := range r.snapshots { - if s.extStartSN == beforeAdjust { + if s.extStartSN == snBeforeAdjust { s.extStartSN = r.extStartSN } } + tsBeforeAdjust := r.extStartTS + r.extStartTS = uint64(rtph.Timestamp) + if r.extStartTS > tsBeforeAdjust { + // wrapping back + r.tsCycles++ + } + r.logger.Infow( + "adjusting starting sequence number", + "snBefore", snBeforeAdjust, + "snAfter", r.extStartSN, + "snCyles", r.cycles, + "tsBefore", tsBeforeAdjust, + "tsAfter", r.extStartTS, + "tsCyles", r.tsCycles, + ) + return true } diff --git a/pkg/sfu/buffer/rtpstats_test.go b/pkg/sfu/buffer/rtpstats_test.go index c5c4138ba..389d330c3 100644 --- a/pkg/sfu/buffer/rtpstats_test.go +++ b/pkg/sfu/buffer/rtpstats_test.go @@ -20,6 +20,7 @@ import ( "testing" "time" + "github.com/livekit/protocol/logger" "github.com/pion/rtp" "github.com/stretchr/testify/require" ) @@ -38,6 +39,7 @@ func TestRTPStats(t *testing.T) { clockRate := uint32(90000) r := NewRTPStats(RTPStatsParams{ ClockRate: clockRate, + Logger: logger.GetLogger(), }) totalDuration := 5 * time.Second @@ -79,6 +81,7 @@ func TestRTPStats_Update(t *testing.T) { clockRate := uint32(90000) r := NewRTPStats(RTPStatsParams{ ClockRate: clockRate, + Logger: logger.GetLogger(), }) sequenceNumber := uint16(rand.Float64() * float64(1<<16)) diff --git a/pkg/sfu/utils/wraparound.go b/pkg/sfu/utils/wraparound.go index 299002fbf..f9f102e1c 100644 --- a/pkg/sfu/utils/wraparound.go +++ b/pkg/sfu/utils/wraparound.go @@ -113,7 +113,7 @@ func (w *WrapAround[T, ET]) maybeAdjustStart(val T) (isRestart bool, preExtended // re-adjust start if necessary. The conditions are // 1. Not seen more than half the range yet - // 1. wrap around compared to start and not completed a half cycle, sequences like (10, 65530) in uint16 space + // 1. wrap back compared to start and not completed a half cycle, sequences like (10, 65530) in uint16 space // 2. no wrap around, but out-of-order compared to start and not completed a half cycle , sequences like (10, 9), (65530, 65528) in uint16 space cycles := w.cycles totalNum := w.GetExtendedHighest() - w.GetExtendedStart() + 1 From 129b1df8e647df1050ecd28d22006cf0d0c4c31f Mon Sep 17 00:00:00 2001 From: Raja Subramanian Date: Thu, 17 Aug 2023 22:33:11 +0530 Subject: [PATCH 18/21] Use VP9 Key frame detection from Galene. (#1973) * Use VP9 Key frame detection from Galene. With ffmpeg generated VP9 file with single layer and publishing via Go SDK, the key picture determination outlined at https://datatracker.ietf.org/doc/html/draft-ietf-payload-vp9-16#page-13 under the F bit explanation does not work. It declares kay frame for pretty much all frames. Unclear if ffmpeg generated bitstream has issues or if that procedure in the above document does not work for single layer case. Using the bit stream explained here https://storage.googleapis.com/downloads.webmproject.org/docs/vp9/vp9-bitstream-specification-v0.6-20160331-draft.pdf (pages 28, 62, 63) implemented in Galene. That is more expensive as it has to parse more, but works in all cases. * Add AV1-TODo * add some TODOs --- pkg/sfu/buffer/helpers.go | 56 +++++++++++---------------------------- pkg/sfu/forwarder.go | 2 ++ pkg/sfu/receiver.go | 5 ++++ 3 files changed, 22 insertions(+), 41 deletions(-) diff --git a/pkg/sfu/buffer/helpers.go b/pkg/sfu/buffer/helpers.go index f52464b4c..274b73e47 100644 --- a/pkg/sfu/buffer/helpers.go +++ b/pkg/sfu/buffer/helpers.go @@ -19,6 +19,7 @@ import ( "errors" "github.com/livekit/protocol/logger" + "github.com/pion/rtp/codecs" ) var ( @@ -310,55 +311,28 @@ func IsH264KeyFrame(payload []byte) bool { // ------------------------------------- +// IsVP9KeyFrame detects if vp9 payload is a keyframe +// taken from https://github.com/jech/galene/blob/master/codecs/codecs.go +// all credits belongs to Juliusz Chroboczek @jech and the awesome Galene SFU func IsVP9KeyFrame(payload []byte) bool { - payloadLen := len(payload) - if payloadLen < 1 { + var vp9 codecs.VP9Packet + _, err := vp9.Unmarshal(payload) + if err != nil || len(vp9.Payload) < 1 { + return false + } + if !vp9.B { return false } - idx := 0 - I := payload[idx]&0x80 > 0 - P := payload[idx]&0x40 > 0 - L := payload[idx]&0x20 > 0 - F := payload[idx]&0x10 > 0 - B := payload[idx]&0x08 > 0 - - if F && !I { + if (vp9.Payload[0] & 0xc0) != 0x80 { return false } - // Check for PictureID - if I { - idx++ - if payloadLen < idx+1 { - return false - } - // Check if m is 1, then Picture ID is 15 bits - if payload[idx]&0x80 > 0 { - idx++ - if payloadLen < idx+1 { - return false - } - } + profile := (vp9.Payload[0] >> 4) & 0x3 + if profile != 3 { + return (vp9.Payload[0] & 0xC) == 0 } - - // Check if TL0PICIDX is present - sid := -1 - if L { - idx++ - if payloadLen < idx+1 { - return false - } - - tid := (payload[idx] >> 5) & 0x7 - if !P && tid != 0 { - return false - } - - sid = int((payload[idx] >> 1) & 0x7) - } - - return !P && (!L || (L && sid == 0)) && B + return (vp9.Payload[0] & 0x6) == 0 } // ------------------------------------- diff --git a/pkg/sfu/forwarder.go b/pkg/sfu/forwarder.go index 696c19817..85d580f18 100644 --- a/pkg/sfu/forwarder.go +++ b/pkg/sfu/forwarder.go @@ -309,6 +309,7 @@ func (f *Forwarder) DetermineCodec(codec webrtc.RTPCodecCapability, extensions [ f.vls = videolayerselector.NewVP9(f.logger) } } + // SVC-TODO: Support for VP9 simulcast. When DD is not available, have to pick selector based on VP9 SVC or Simulcast case "video/av1": // DD-TODO : we only enable dd layer selector for av1/vp9 now, in the future we can enable it for vp8 too if f.vls != nil { @@ -316,6 +317,7 @@ func (f *Forwarder) DetermineCodec(codec webrtc.RTPCodecCapability, extensions [ } else { f.vls = videolayerselector.NewDependencyDescriptor(f.logger) } + // SVC-TODO: Support for AV1 Simulcast or just single spatial layer - won't have DD in that case } } diff --git a/pkg/sfu/receiver.go b/pkg/sfu/receiver.go index 69d3d1265..8aa5dcac3 100644 --- a/pkg/sfu/receiver.go +++ b/pkg/sfu/receiver.go @@ -131,6 +131,10 @@ type WebRTCReceiver struct { redPktWriter func(pkt *buffer.ExtPacket, spatialLayer int32) } +// SVC-TODO: Have to use more conditions to differentiate between +// SVC-TODO: SVC and non-SVC (could be single layer or simulcast). +// SVC-TODO: May only need to differentiate between simulcast and non-simulcast +// SVC-TODO: i. e. may be possible to treat single layer as SVC to get proper/intended functionality. func IsSvcCodec(mime string) bool { switch strings.ToLower(mime) { case "video/av1": @@ -231,6 +235,7 @@ func NewWebRTCReceiver( }) w.connectionStats.Start(w.trackInfo) + // SVC-TODO: Handle DD for non-SVC cases??? if w.isSVC { for _, ext := range receiver.GetParameters().HeaderExtensions { if ext.URI == dd.ExtensionURI { From 1a32439d7e8e2494cbc9f90a47e9c5d3e871574a Mon Sep 17 00:00:00 2001 From: Raja Subramanian Date: Fri, 18 Aug 2023 02:00:43 +0530 Subject: [PATCH 19/21] Ensure older session does not clobeer newer session. (#1974) --- pkg/rtc/participant_signal.go | 3 +-- pkg/rtc/room.go | 9 +++++++++ 2 files changed, 10 insertions(+), 2 deletions(-) diff --git a/pkg/rtc/participant_signal.go b/pkg/rtc/participant_signal.go index a9ae4dfab..e634fa573 100644 --- a/pkg/rtc/participant_signal.go +++ b/pkg/rtc/participant_signal.go @@ -58,8 +58,7 @@ func (p *ParticipantImpl) SendJoinResponse(joinResponse *livekit.JoinResponse) e return err } - // update state after to sending message, so that no participant updates could slip through before JoinResponse is - // sent + // update state after sending message, so that no participant updates could slip through before JoinResponse is sent p.updateLock.Lock() if p.State() == livekit.ParticipantInfo_JOINING { p.updateState(livekit.ParticipantInfo_JOINED) diff --git a/pkg/rtc/room.go b/pkg/rtc/room.go index 7d8a12a03..f614f8979 100644 --- a/pkg/rtc/room.go +++ b/pkg/rtc/room.go @@ -1069,6 +1069,15 @@ func (r *Room) pushAndDequeueUpdates(pi *livekit.ParticipantInfo, isImmediate bo return nil } } + } else { + ep := r.GetParticipant(identity) + if ep != nil { + epi := ep.ToProto() + if epi.JoinedAt > pi.JoinedAt { + // older session update, newer session has already become active, so nothing to do + return nil + } + } } if shouldSend { From ee8811509759cd17e3619f8bcc7543691dd8b9fe Mon Sep 17 00:00:00 2001 From: Raja Subramanian Date: Fri, 18 Aug 2023 09:52:02 +0530 Subject: [PATCH 20/21] Demote noisy logs (#1976) --- pkg/sfu/forwarder.go | 14 +++++--------- pkg/sfu/streamtrackermanager.go | 2 +- 2 files changed, 6 insertions(+), 10 deletions(-) diff --git a/pkg/sfu/forwarder.go b/pkg/sfu/forwarder.go index 85d580f18..1d5c5ac7f 100644 --- a/pkg/sfu/forwarder.go +++ b/pkg/sfu/forwarder.go @@ -1335,11 +1335,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 { - if reason == "optimal" { - f.logger.Debugw(fmt.Sprintf("stream allocation: %s", reason), "allocation", alloc) - } else { - f.logger.Infow(fmt.Sprintf("stream allocation: %s", reason), "allocation", alloc) - } + f.logger.Debugw(fmt.Sprintf("stream allocation: %s", reason), "allocation", alloc) } f.lastAllocation = alloc @@ -1434,7 +1430,7 @@ func (f *Forwarder) processSourceSwitch(extPkt *buffer.ExtPacket, layer int32) e f.referenceLayerSpatial = layer f.rtpMunger.SetLastSnTs(extPkt) f.codecMunger.SetLast(extPkt) - f.logger.Infow( + f.logger.Debugw( "starting forwarding", "sequenceNumber", extPkt.Packet.SequenceNumber, "timestamp", extPkt.Packet.Timestamp, @@ -1445,7 +1441,7 @@ func (f *Forwarder) processSourceSwitch(extPkt *buffer.ExtPacket, layer int32) e } logTransition := func(message string, expectedTS, refTS, lastTS uint32, diffSeconds float64) { - f.logger.Infow( + f.logger.Debugw( message, "layer", layer, "expectedTS", expectedTS, @@ -1575,11 +1571,11 @@ func (f *Forwarder) processSourceSwitch(extPkt *buffer.ExtPacket, layer int32) e } if nextTS-lastTS == 0 || nextTS-lastTS > (1<<31) { - f.logger.Infow("next timestamp is before last, adjusting", "nextTS", nextTS, "lastTS", lastTS) + f.logger.Debugw("next timestamp is before last, adjusting", "nextTS", nextTS, "lastTS", lastTS) // nominal increase nextTS = lastTS + 1 } - f.logger.Infow( + f.logger.Debugw( "next timestamp on switch", "switchingAt", switchingAt.String(), "layer", layer, diff --git a/pkg/sfu/streamtrackermanager.go b/pkg/sfu/streamtrackermanager.go index 8f3c45190..9aa82f91e 100644 --- a/pkg/sfu/streamtrackermanager.go +++ b/pkg/sfu/streamtrackermanager.go @@ -571,7 +571,7 @@ func (s *StreamTrackerManager) updateLayerOffsetLocked(ref, other int32) { // use minimal offset to indicate value availability in the extremely unlikely case of // both layers using the same timestamp if offset == 0 { - s.logger.Infow( + s.logger.Debugw( "using default offset", "ref", ref, "refNTP", srRef.NTPTimestamp.Time().String(), From ded2aec288796ffcb47fbac3c2d7e1b3d4fee14f Mon Sep 17 00:00:00 2001 From: Raja Subramanian Date: Fri, 18 Aug 2023 10:26:59 +0530 Subject: [PATCH 21/21] Demote noisy log (#1977) --- pkg/sfu/videolayerselector/base.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pkg/sfu/videolayerselector/base.go b/pkg/sfu/videolayerselector/base.go index 346632cb9..08b61e308 100644 --- a/pkg/sfu/videolayerselector/base.go +++ b/pkg/sfu/videolayerselector/base.go @@ -126,7 +126,7 @@ func (b *Base) Select(_extPkt *buffer.ExtPacket, _layer int32) (result VideoLaye } func (b *Base) Rollback() { - b.logger.Infow( + b.logger.Debugw( "rolling back", "previous", b.previousLayer, "current", b.currentLayer,