From c09d8d0878d26e63f2eb39f9b73b6aa25dde7751 Mon Sep 17 00:00:00 2001 From: Raja Subramanian Date: Mon, 11 Sep 2023 07:33:39 +0530 Subject: [PATCH] Split RTPStats into receiver and sender. (#2055) * Split RTPStats into receiver and sender. For receiver, short types are input and need to calculate extended type. For sender (subscriber), it can operate only in extended type. This makes the subscriber side a little simpler and should make it more efficient as it can do simple comparisons in extended type space. There was also an issue with subscriber using shorter type and calculating extended type. When subscriber starts after the publisher has already rolled over in sequence number OR timestamp, when subsequent publisher side sender reports are used to adjust subscriber time stamps, they were out of whack. Using extended type on subscriber does not face that. * fix test * extended types from sequencer * log --- pkg/rtc/mediatrack.go | 4 +- pkg/sfu/buffer/buffer.go | 22 +- pkg/sfu/buffer/rtpstats.go | 2003 ----------------- pkg/sfu/buffer/rtpstats_base.go | 1254 +++++++++++ pkg/sfu/buffer/rtpstats_receiver.go | 471 ++++ ...tats_test.go => rtpstats_receiver_test.go} | 138 +- pkg/sfu/buffer/rtpstats_sender.go | 618 +++++ pkg/sfu/connectionquality/connectionstats.go | 8 +- pkg/sfu/downtrack.go | 129 +- pkg/sfu/pacer/base.go | 2 +- pkg/sfu/pacer/pacer.go | 2 +- pkg/sfu/sequencer.go | 35 +- pkg/sfu/sequencer_test.go | 28 +- 13 files changed, 2592 insertions(+), 2122 deletions(-) delete mode 100644 pkg/sfu/buffer/rtpstats.go create mode 100644 pkg/sfu/buffer/rtpstats_base.go create mode 100644 pkg/sfu/buffer/rtpstats_receiver.go rename pkg/sfu/buffer/{rtpstats_test.go => rtpstats_receiver_test.go} (69%) create mode 100644 pkg/sfu/buffer/rtpstats_sender.go diff --git a/pkg/rtc/mediatrack.go b/pkg/rtc/mediatrack.go index 365b7434a..856527635 100644 --- a/pkg/rtc/mediatrack.go +++ b/pkg/rtc/mediatrack.go @@ -327,14 +327,14 @@ func (t *MediaTrack) AddReceiver(receiver *webrtc.RTPReceiver, track *webrtc.Tra t.MediaTrackSubscriptions.UpdateVideoLayers() }) - buff.OnFinalRtpStats(func(stats *buffer.RTPStats) { + buff.OnFinalRtpStats(func(stats *livekit.RTPStats) { t.params.Telemetry.TrackPublishRTPStats( context.Background(), t.params.ParticipantID, t.ID(), mime, int(layer), - stats.ToProto(), + stats, ) }) return newCodec diff --git a/pkg/sfu/buffer/buffer.go b/pkg/sfu/buffer/buffer.go index 293b0f1fc..d0d009f2e 100644 --- a/pkg/sfu/buffer/buffer.go +++ b/pkg/sfu/buffer/buffer.go @@ -97,7 +97,7 @@ type Buffer struct { pliThrottle int64 - rtpStats *RTPStats + rtpStats *RTPStatsReceiver rrSnapshotId uint32 deltaStatsSnapshotId uint32 @@ -108,7 +108,7 @@ type Buffer struct { onRtcpFeedback func([]rtcp.Packet) onRtcpSenderReport func() onFpsChanged func() - onFinalRtpStats func(*RTPStats) + onFinalRtpStats func(*livekit.RTPStats) // logger logger logger.Logger @@ -175,7 +175,7 @@ func (b *Buffer) Bind(params webrtc.RTPParameters, codec webrtc.RTPCodecCapabili return } - b.rtpStats = NewRTPStats(RTPStatsParams{ + b.rtpStats = NewRTPStatsReceiver(RTPStatsParams{ ClockRate: codec.ClockRate, Logger: b.logger, }) @@ -350,7 +350,7 @@ func (b *Buffer) Close() error { b.rtpStats.Stop() b.logger.Infow("rtp stats", "direction", "upstream", "stats", b.rtpStats.ToString()) if b.onFinalRtpStats != nil { - b.onFinalRtpStats(b.rtpStats) + b.onFinalRtpStats(b.rtpStats.ToProto()) } } @@ -530,7 +530,15 @@ func (b *Buffer) doFpsCalc(ep *ExtPacket) { } func (b *Buffer) updateStreamState(p *rtp.Packet, arrivalTime time.Time) RTPFlowState { - flowState := b.rtpStats.Update(&p.Header, len(p.Payload), int(p.PaddingSize), arrivalTime) + flowState := b.rtpStats.Update( + arrivalTime, + p.Header.SequenceNumber, + p.Header.Timestamp, + p.Header.Marker, + p.Header.MarshalSize(), + len(p.Payload), + int(p.PaddingSize), + ) if b.nacker != nil { b.nacker.Remove(p.SequenceNumber) @@ -693,7 +701,7 @@ func (b *Buffer) buildReceptionReport() *rtcp.ReceptionReport { return nil } - return b.rtpStats.SnapshotRtcpReceptionReport(b.mediaSSRC, b.lastFractionLostToReport, b.rrSnapshotId) + return b.rtpStats.GetRtcpReceptionReport(b.mediaSSRC, b.lastFractionLostToReport, b.rrSnapshotId) } func (b *Buffer) SetSenderReportData(rtpTime uint32, ntpTime uint64, packetCount uint32) { @@ -770,7 +778,7 @@ func (b *Buffer) OnRtcpSenderReport(fn func()) { b.onRtcpSenderReport = fn } -func (b *Buffer) OnFinalRtpStats(fn func(*RTPStats)) { +func (b *Buffer) OnFinalRtpStats(fn func(*livekit.RTPStats)) { b.onFinalRtpStats = fn } diff --git a/pkg/sfu/buffer/rtpstats.go b/pkg/sfu/buffer/rtpstats.go deleted file mode 100644 index 9fb57c6c5..000000000 --- a/pkg/sfu/buffer/rtpstats.go +++ /dev/null @@ -1,2003 +0,0 @@ -// Copyright 2023 LiveKit, Inc. -// -// Licensed under the Apache License, Version 2.0 (the "License"); -// you may not use this file except in compliance with the License. -// You may obtain a copy of the License at -// -// http://www.apache.org/licenses/LICENSE-2.0 -// -// Unless required by applicable law or agreed to in writing, software -// distributed under the License is distributed on an "AS IS" BASIS, -// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -// See the License for the specific language governing permissions and -// limitations under the License. - -package buffer - -import ( - "errors" - "fmt" - "sync" - "time" - - "github.com/pion/rtcp" - "github.com/pion/rtp" - "google.golang.org/protobuf/types/known/timestamppb" - - "github.com/livekit/livekit-server/pkg/sfu/utils" - "github.com/livekit/mediatransportutil" - "github.com/livekit/protocol/livekit" - "github.com/livekit/protocol/logger" -) - -const ( - GapHistogramNumBins = 101 - NumSequenceNumbers = 65536 - FirstSnapshotId = 1 - SnInfoSize = 8192 - SnInfoMask = SnInfoSize - 1 - - firstPacketTimeAdjustWindow = 2 * time.Minute - firstPacketTimeAdjustThreshold = 5 * time.Second -) - -// ------------------------------------------------------- - -func RTPDriftToString(r *livekit.RTPDrift) string { - if r == nil { - return "-" - } - - str := fmt.Sprintf("t: %+v|%+v|%.2fs", r.StartTime.AsTime().Format(time.UnixDate), r.EndTime.AsTime().Format(time.UnixDate), r.Duration) - str += fmt.Sprintf(", ts: %d|%d|%d", r.StartTimestamp, r.EndTimestamp, r.RtpClockTicks) - str += fmt.Sprintf(", d: %d|%.2fms", r.DriftSamples, r.DriftMs) - str += fmt.Sprintf(", cr: %.2f", r.ClockRate) - return str -} - -// ------------------------------------------------------- - -type RTPFlowState struct { - IsNotHandled bool - - HasLoss bool - LossStartInclusive uint64 - LossEndExclusive uint64 - - IsDuplicate bool - IsOutOfOrder bool - - ExtSequenceNumber uint64 - ExtTimestamp uint64 -} - -type IntervalStats struct { - packets uint64 - bytes uint64 - headerBytes uint64 - packetsPadding uint64 - bytesPadding uint64 - headerBytesPadding uint64 - packetsLost uint64 - packetsOutOfOrder uint64 - frames uint32 -} - -type RTPDeltaInfo struct { - StartTime time.Time - Duration time.Duration - Packets uint32 - Bytes uint64 - HeaderBytes uint64 - PacketsDuplicate uint32 - BytesDuplicate uint64 - HeaderBytesDuplicate uint64 - PacketsPadding uint32 - BytesPadding uint64 - HeaderBytesPadding uint64 - PacketsLost uint32 - PacketsMissing uint32 - PacketsOutOfOrder uint32 - Frames uint32 - RttMax uint32 - JitterMax float64 - Nacks uint32 - Plis uint32 - Firs uint32 -} - -type Snapshot struct { - startTime time.Time - extStartSN uint64 - extStartSNOverridden uint64 - packetsDuplicate uint64 - bytesDuplicate uint64 - headerBytesDuplicate uint64 - packetsLostOverridden uint64 - nacks uint32 - plis uint32 - firs uint32 - maxRtt uint32 - maxJitter float64 - maxJitterOverridden float64 -} - -type SnInfo struct { - hdrSize uint16 - pktSize uint16 - isPaddingOnly bool - marker bool - isOutOfOrder bool -} - -type RTCPSenderReportData struct { - RTPTimestamp uint32 - RTPTimestampExt uint64 - NTPTimestamp mediatransportutil.NtpTime - PacketCount uint32 - PacketCountExt uint64 - PaddingOnlyDrops uint64 - At time.Time -} - -type RTPStatsParams struct { - ClockRate uint32 - IsReceiverReportDriven bool - Logger logger.Logger -} - -type RTPStats struct { - params RTPStatsParams - logger logger.Logger - - lock sync.RWMutex - - initialized bool - resyncOnNextPacket bool - shouldDiscountPaddingOnlyDrops bool - - startTime time.Time - endTime time.Time - - sequenceNumber *utils.WrapAround[uint16, uint64] - - extHighestSNOverridden uint64 - lastRRTime time.Time - lastRR rtcp.ReceptionReport - - timestamp *utils.WrapAround[uint32, uint64] - - firstTime time.Time - highestTime time.Time - - lastTransit uint32 - lastJitterRTP uint32 - - bytes uint64 - headerBytes uint64 - bytesDuplicate uint64 - headerBytesDuplicate uint64 - bytesPadding uint64 - headerBytesPadding uint64 - packetsDuplicate uint64 - packetsPadding uint64 - - packetsOutOfOrder uint64 - - packetsLost uint64 - packetsLostOverridden uint64 - - frames uint32 - - jitter float64 - maxJitter float64 - jitterOverridden float64 - maxJitterOverridden float64 - - snInfos [SnInfoSize]SnInfo - - gapHistogram [GapHistogramNumBins]uint32 - - nacks uint32 - nackAcks uint32 - nackMisses uint32 - nackRepeated uint32 - - plis uint32 - lastPli time.Time - - layerLockPlis uint32 - lastLayerLockPli time.Time - - firs uint32 - lastFir time.Time - - keyFrames uint32 - lastKeyFrame time.Time - - rtt uint32 - maxRtt uint32 - - srFirst *RTCPSenderReportData - srNewest *RTCPSenderReportData - - nextSnapshotId uint32 - snapshots map[uint32]*Snapshot -} - -func NewRTPStats(params RTPStatsParams) *RTPStats { - return &RTPStats{ - params: params, - logger: params.Logger, - sequenceNumber: utils.NewWrapAround[uint16, uint64](), - timestamp: utils.NewWrapAround[uint32, uint64](), - nextSnapshotId: FirstSnapshotId, - snapshots: make(map[uint32]*Snapshot), - } -} - -func (r *RTPStats) Seed(from *RTPStats) { - r.lock.Lock() - defer r.lock.Unlock() - - if from == nil || !from.initialized { - return - } - - r.initialized = from.initialized - r.resyncOnNextPacket = from.resyncOnNextPacket - r.shouldDiscountPaddingOnlyDrops = from.shouldDiscountPaddingOnlyDrops - - r.startTime = from.startTime - // do not clone endTime as a non-zero endTime indicates an ended object - - r.sequenceNumber.Seed(from.sequenceNumber) - - r.extHighestSNOverridden = from.extHighestSNOverridden - r.lastRRTime = from.lastRRTime - r.lastRR = from.lastRR - - r.timestamp.Seed(from.timestamp) - - r.firstTime = from.firstTime - r.highestTime = from.highestTime - - r.lastTransit = from.lastTransit - r.lastJitterRTP = from.lastJitterRTP - - r.bytes = from.bytes - r.headerBytes = from.headerBytes - r.bytesDuplicate = from.bytesDuplicate - r.headerBytesDuplicate = from.headerBytesDuplicate - r.bytesPadding = from.bytesPadding - r.headerBytesPadding = from.headerBytesPadding - r.packetsDuplicate = from.packetsDuplicate - r.packetsPadding = from.packetsPadding - - r.packetsOutOfOrder = from.packetsOutOfOrder - - r.packetsLost = from.packetsLost - r.packetsLostOverridden = from.packetsLostOverridden - - r.frames = from.frames - - r.jitter = from.jitter - r.maxJitter = from.maxJitter - r.jitterOverridden = from.jitterOverridden - r.maxJitterOverridden = from.maxJitterOverridden - - r.snInfos = from.snInfos - - r.gapHistogram = from.gapHistogram - - r.nacks = from.nacks - r.nackAcks = from.nackAcks - r.nackMisses = from.nackMisses - r.nackRepeated = from.nackRepeated - - r.plis = from.plis - r.lastPli = from.lastPli - - r.layerLockPlis = from.layerLockPlis - r.lastLayerLockPli = from.lastLayerLockPli - - r.firs = from.firs - r.lastFir = from.lastFir - - r.keyFrames = from.keyFrames - r.lastKeyFrame = from.lastKeyFrame - - r.rtt = from.rtt - r.maxRtt = from.maxRtt - - if from.srFirst != nil { - srFirst := *from.srFirst - r.srFirst = &srFirst - } else { - r.srFirst = nil - } - if from.srNewest != nil { - srNewest := *from.srNewest - r.srNewest = &srNewest - } else { - r.srNewest = nil - } - - r.nextSnapshotId = from.nextSnapshotId - for id, ss := range from.snapshots { - ssCopy := *ss - r.snapshots[id] = &ssCopy - } -} - -func (r *RTPStats) SetLogger(logger logger.Logger) { - r.logger = logger -} - -func (r *RTPStats) Stop() { - r.lock.Lock() - defer r.lock.Unlock() - - r.endTime = time.Now() -} - -func (r *RTPStats) NewSnapshotId() uint32 { - r.lock.Lock() - defer r.lock.Unlock() - - id := r.nextSnapshotId - if r.initialized { - extStartSN := r.sequenceNumber.GetExtendedStart() - r.snapshots[id] = &Snapshot{ - startTime: time.Now(), - extStartSN: extStartSN, - extStartSNOverridden: extStartSN, - } - } - - r.nextSnapshotId++ - - return id -} - -func (r *RTPStats) IsActive() bool { - r.lock.RLock() - defer r.lock.RUnlock() - - return r.initialized && r.endTime.IsZero() -} - -func (r *RTPStats) Update(rtph *rtp.Header, payloadSize int, paddingSize int, packetTime time.Time) (flowState RTPFlowState) { - r.lock.Lock() - defer r.lock.Unlock() - - if !r.endTime.IsZero() { - flowState.IsNotHandled = true - return - } - - if r.resyncOnNextPacket { - r.resyncOnNextPacket = false - - if r.initialized { - extHighestSN := r.sequenceNumber.GetExtendedHighest() - var newestPacketCount uint64 - var paddingOnlyDrops uint64 - var extExpectedHighestSN uint64 - var expectedHighestSN uint16 - var snCycles uint64 - - extHighestTS := r.timestamp.GetExtendedHighest() - var newestTS uint64 - var extExpectedHighestTS uint64 - var expectedHighestTS uint32 - var tsCycles uint64 - if r.srNewest != nil { - newestPacketCount = r.srNewest.PacketCountExt - paddingOnlyDrops = r.srNewest.PaddingOnlyDrops - if newestPacketCount != 0 { - extExpectedHighestSN = r.sequenceNumber.GetExtendedStart() + newestPacketCount - if r.shouldDiscountPaddingOnlyDrops { - extExpectedHighestSN -= paddingOnlyDrops - } - expectedHighestSN = uint16(extExpectedHighestSN & 0xFFFF) - snCycles = extExpectedHighestSN & 0xFFFF_FFFF_FFFF_0000 - if rtph.SequenceNumber-expectedHighestSN < (1<<15) && rtph.SequenceNumber < expectedHighestSN { - snCycles += (1 << 16) - } - if snCycles != 0 && expectedHighestSN-rtph.SequenceNumber < (1<<15) && expectedHighestSN < rtph.SequenceNumber { - snCycles -= (1 << 16) - } - } - - newestTS = r.srNewest.RTPTimestampExt - extExpectedHighestTS = newestTS - expectedHighestTS = uint32(extExpectedHighestTS & 0xFFFF_FFFF) - tsCycles = extExpectedHighestTS & 0xFFFF_FFFF_0000_0000 - if rtph.Timestamp-expectedHighestTS < (1<<31) && rtph.Timestamp < expectedHighestTS { - tsCycles += (1 << 32) - } - if tsCycles != 0 && expectedHighestTS-rtph.Timestamp < (1<<31) && expectedHighestTS < rtph.Timestamp { - tsCycles -= (1 << 32) - } - } - r.sequenceNumber.ResetHighest(snCycles + uint64(rtph.SequenceNumber) - 1) - r.timestamp.ResetHighest(tsCycles + uint64(rtph.Timestamp)) - r.highestTime = packetTime - r.logger.Debugw( - "resync", - "newestPacketCount", newestPacketCount, - "paddingOnlyDrops", paddingOnlyDrops, - "extExpectedHighestSN", extExpectedHighestSN, - "expectedHighestSN", expectedHighestSN, - "snCycles", snCycles, - "rtpSN", rtph.SequenceNumber, - "beforeExtHighestSN", extHighestSN, - "afterExtHighestSN", r.sequenceNumber.GetExtendedHighest(), - "newestTS", newestTS, - "extExpectedHighestTS", extExpectedHighestTS, - "expectedHighestTS", expectedHighestTS, - "tsCycles", tsCycles, - "rtpTS", rtph.Timestamp, - "beforeExtHighestTS", extHighestTS, - "afterExtHighestTS", r.timestamp.GetExtendedHighest(), - ) - } - } - - var resSN utils.WrapAroundUpdateResult[uint64] - var resTS utils.WrapAroundUpdateResult[uint64] - if !r.initialized { - if payloadSize == 0 { - // do not start on a padding only packet - flowState.IsNotHandled = true - return - } - - r.initialized = true - - r.startTime = time.Now() - - r.firstTime = packetTime - r.highestTime = packetTime - - resSN = r.sequenceNumber.Update(rtph.SequenceNumber) - resTS = r.timestamp.Update(rtph.Timestamp) - - // initialize snapshots if any - for i := uint32(FirstSnapshotId); i < r.nextSnapshotId; i++ { - extStartSN := r.sequenceNumber.GetExtendedStart() - r.snapshots[i] = &Snapshot{ - startTime: r.startTime, - extStartSN: extStartSN, - extStartSNOverridden: extStartSN, - } - } - - r.logger.Debugw( - "rtp stream start", - "startTime", r.startTime.String(), - "firstTime", r.firstTime.String(), - "startSN", r.sequenceNumber.GetExtendedStart(), - "startTS", r.timestamp.GetExtendedStart(), - ) - } else { - resSN = r.sequenceNumber.Update(rtph.SequenceNumber) - resTS = r.timestamp.Update(rtph.Timestamp) - } - - hdrSize := uint64(rtph.MarshalSize()) - pktSize := hdrSize + uint64(payloadSize+paddingSize) - gapSN := int64(resSN.ExtendedVal - resSN.PreExtendedHighest) - if gapSN <= 0 { // duplicate OR out-of-order - if payloadSize == 0 { - // do not start on a padding only packet - if resTS.IsRestart { - r.logger.Infow("rolling back timestamp restart", "tsBefore", r.timestamp.GetExtendedStart(), "tsAfter", resTS.PreExtendedStart) - r.timestamp.RollbackRestart(resTS.PreExtendedStart) - } - if resSN.IsRestart { - r.logger.Infow("rolling back sequence number restart", "snBefore", r.sequenceNumber.GetExtendedStart(), "snAfter", resSN.PreExtendedStart) - r.sequenceNumber.RollbackRestart(resSN.PreExtendedStart) - return - } - } - - if gapSN != 0 { - r.packetsOutOfOrder++ - } - - if resSN.IsRestart { - r.packetsLost += resSN.PreExtendedStart - resSN.ExtendedVal - - extStartSN := r.sequenceNumber.GetExtendedStart() - for _, s := range r.snapshots { - if s.extStartSN == resSN.PreExtendedStart { - s.extStartSN = extStartSN - } - } - - r.logger.Infow( - "adjusting start sequence number", - "snBefore", resSN.PreExtendedStart, - "snAfter", resSN.ExtendedVal, - ) - } - - if resTS.IsRestart { - r.logger.Infow( - "adjusting start timestamp", - "tsBefore", resTS.PreExtendedStart, - "tsAfter", resTS.ExtendedVal, - ) - } - - if !r.isSnInfoLost(resSN.ExtendedVal, resSN.PreExtendedHighest) { - r.bytesDuplicate += pktSize - r.headerBytesDuplicate += hdrSize - r.packetsDuplicate++ - flowState.IsDuplicate = true - } else { - r.packetsLost-- - r.setSnInfo(resSN.ExtendedVal, resSN.PreExtendedHighest, uint16(pktSize), uint16(hdrSize), uint16(payloadSize), rtph.Marker, true) - } - - flowState.IsOutOfOrder = true - flowState.ExtSequenceNumber = resSN.ExtendedVal - flowState.ExtTimestamp = resTS.ExtendedVal - } else { // in-order - // update gap histogram - r.updateGapHistogram(int(gapSN)) - - // update missing sequence numbers - r.clearSnInfos(resSN.PreExtendedHighest+1, resSN.ExtendedVal) - r.packetsLost += uint64(gapSN - 1) - - r.setSnInfo(resSN.ExtendedVal, resSN.PreExtendedHighest, uint16(pktSize), uint16(hdrSize), uint16(payloadSize), rtph.Marker, false) - - if rtph.Timestamp != uint32(resTS.PreExtendedHighest) { - // update only on first packet as same timestamp could be in multiple packets. - // NOTE: this may not be the first packet with this time stamp if there is packet loss. - r.highestTime = packetTime - } - - if gapSN > 1 { - flowState.HasLoss = true - flowState.LossStartInclusive = resSN.PreExtendedHighest + 1 - flowState.LossEndExclusive = resSN.ExtendedVal - } - flowState.ExtSequenceNumber = resSN.ExtendedVal - flowState.ExtTimestamp = resTS.ExtendedVal - } - - if !flowState.IsDuplicate { - if payloadSize == 0 { - r.packetsPadding++ - r.bytesPadding += pktSize - r.headerBytesPadding += hdrSize - } else { - r.bytes += pktSize - r.headerBytes += hdrSize - - if rtph.Marker { - r.frames++ - } - - r.updateJitter(rtph, packetTime) - } - } - return -} - -func (r *RTPStats) ResyncOnNextPacket(shouldDiscountPaddingOnlyDrops bool) { - r.lock.Lock() - defer r.lock.Unlock() - - r.resyncOnNextPacket = true - r.shouldDiscountPaddingOnlyDrops = shouldDiscountPaddingOnlyDrops -} - -func (r *RTPStats) getPacketsExpected() uint64 { - return r.sequenceNumber.GetExtendedHighest() - r.sequenceNumber.GetExtendedStart() + 1 -} - -func (r *RTPStats) GetTotalPacketsPrimary() uint64 { - r.lock.RLock() - defer r.lock.RUnlock() - - return r.getTotalPacketsPrimary() -} - -func (r *RTPStats) getTotalPacketsPrimary() uint64 { - packetsExpected := r.getPacketsExpected() - if r.packetsLost > packetsExpected { - // should not happen - return 0 - } - - packetsSeen := packetsExpected - r.packetsLost - if r.packetsPadding > packetsSeen { - return 0 - } - - return packetsSeen - r.packetsPadding -} - -func (r *RTPStats) UpdateFromReceiverReport(rr rtcp.ReceptionReport) (rtt uint32, isRttChanged bool) { - r.lock.Lock() - defer r.lock.Unlock() - - if !r.initialized || !r.endTime.IsZero() || !r.params.IsReceiverReportDriven { - // it is possible that the `LastSequenceNumber` in the receiver report is before the starting - // sequence number when dummy packets are used to trigger Pion's OnTrack path. - return - } - - extHighestSNOverridden := r.extHighestSNOverridden&0xFFFF_FFFF_0000_0000 + uint64(rr.LastSequenceNumber) - if !r.lastRRTime.IsZero() { - if (rr.LastSequenceNumber-r.lastRR.LastSequenceNumber) < (1<<31) && rr.LastSequenceNumber < r.lastRR.LastSequenceNumber { - extHighestSNOverridden += (1 << 32) - } - } - if extHighestSNOverridden < r.sequenceNumber.GetExtendedStart() { - // it is possible that the `LastSequenceNumber` in the receiver report is before the starting - // sequence number when dummy packets are used to trigger Pion's OnTrack path. - return - } - - var err error - if r.srNewest != nil { - rtt, err = mediatransportutil.GetRttMs(&rr, r.srNewest.NTPTimestamp, r.srNewest.At) - if err == nil { - isRttChanged = rtt != r.rtt - } else { - if !errors.Is(err, mediatransportutil.ErrRttNotLastSenderReport) && !errors.Is(err, mediatransportutil.ErrRttNoLastSenderReport) { - r.logger.Warnw("error getting rtt", err) - } - } - } - - if r.lastRRTime.IsZero() || r.extHighestSNOverridden <= extHighestSNOverridden { - r.extHighestSNOverridden = extHighestSNOverridden - - packetsLostOverridden := r.packetsLostOverridden&0xFFFF_FFFF_0000_0000 + uint64(rr.TotalLost) - if (rr.TotalLost-r.lastRR.TotalLost) < (1<<31) && rr.TotalLost < r.lastRR.TotalLost { - packetsLostOverridden += (1 << 32) - } - r.packetsLostOverridden = packetsLostOverridden - - if isRttChanged { - r.rtt = rtt - if rtt > r.maxRtt { - r.maxRtt = rtt - } - } - - r.jitterOverridden = float64(rr.Jitter) - if r.jitterOverridden > r.maxJitterOverridden { - r.maxJitterOverridden = r.jitterOverridden - } - - // update snapshots - for _, s := range r.snapshots { - if isRttChanged && rtt > s.maxRtt { - s.maxRtt = rtt - } - - if r.jitterOverridden > s.maxJitterOverridden { - s.maxJitterOverridden = r.jitterOverridden - } - } - - r.lastRRTime = time.Now() - r.lastRR = rr - } else { - r.logger.Debugw( - fmt.Sprintf("receiver report potentially out of order, highestSN: existing: %d, received: %d", r.extHighestSNOverridden, rr.LastSequenceNumber), - "lastRRTime", r.lastRRTime, - "lastRR", r.lastRR, - "sinceLastRR", time.Since(r.lastRRTime), - "receivedRR", rr, - ) - } - return -} - -func (r *RTPStats) LastReceiverReportTime() time.Time { - r.lock.RLock() - defer r.lock.RUnlock() - - return r.lastRRTime -} - -func (r *RTPStats) UpdateNack(nackCount uint32) { - r.lock.Lock() - defer r.lock.Unlock() - - if !r.endTime.IsZero() { - return - } - - r.nacks += nackCount -} - -func (r *RTPStats) UpdateNackProcessed(nackAckCount uint32, nackMissCount uint32, nackRepeatedCount uint32) { - r.lock.Lock() - defer r.lock.Unlock() - - if !r.endTime.IsZero() { - return - } - - r.nackAcks += nackAckCount - r.nackMisses += nackMissCount - r.nackRepeated += nackRepeatedCount -} - -func (r *RTPStats) UpdatePliAndTime(pliCount uint32) { - r.lock.Lock() - defer r.lock.Unlock() - - if !r.endTime.IsZero() { - return - } - - r.updatePliLocked(pliCount) - r.updatePliTimeLocked() -} - -func (r *RTPStats) UpdatePli(pliCount uint32) { - r.lock.Lock() - defer r.lock.Unlock() - - if !r.endTime.IsZero() { - return - } - - r.updatePliLocked(pliCount) -} - -func (r *RTPStats) updatePliLocked(pliCount uint32) { - r.plis += pliCount -} - -func (r *RTPStats) UpdatePliTime() { - r.lock.Lock() - defer r.lock.Unlock() - - if !r.endTime.IsZero() { - return - } - - r.updatePliTimeLocked() -} - -func (r *RTPStats) updatePliTimeLocked() { - r.lastPli = time.Now() -} - -func (r *RTPStats) LastPli() time.Time { - r.lock.RLock() - defer r.lock.RUnlock() - - return r.lastPli -} - -func (r *RTPStats) TimeSinceLastPli() int64 { - r.lock.RLock() - defer r.lock.RUnlock() - - return time.Now().UnixNano() - r.lastPli.UnixNano() -} - -func (r *RTPStats) UpdateLayerLockPliAndTime(pliCount uint32) { - r.lock.Lock() - defer r.lock.Unlock() - - if !r.endTime.IsZero() { - return - } - - r.layerLockPlis += pliCount - r.lastLayerLockPli = time.Now() -} - -func (r *RTPStats) UpdateFir(firCount uint32) { - r.lock.Lock() - defer r.lock.Unlock() - - if !r.endTime.IsZero() { - return - } - - r.firs += firCount -} - -func (r *RTPStats) UpdateFirTime() { - r.lock.Lock() - defer r.lock.Unlock() - - if !r.endTime.IsZero() { - return - } - - r.lastFir = time.Now() -} - -func (r *RTPStats) UpdateKeyFrame(kfCount uint32) { - r.lock.Lock() - defer r.lock.Unlock() - - if !r.endTime.IsZero() { - return - } - - r.keyFrames += kfCount - r.lastKeyFrame = time.Now() -} - -func (r *RTPStats) UpdateRtt(rtt uint32) { - r.lock.Lock() - defer r.lock.Unlock() - - if !r.endTime.IsZero() { - return - } - - r.rtt = rtt - if rtt > r.maxRtt { - r.maxRtt = rtt - } - - for _, s := range r.snapshots { - if rtt > s.maxRtt { - s.maxRtt = rtt - } - } -} - -func (r *RTPStats) GetRtt() uint32 { - r.lock.RLock() - defer r.lock.RUnlock() - - return r.rtt -} - -func (r *RTPStats) MaybeAdjustFirstPacketTime(ets uint64) { - r.lock.Lock() - defer r.lock.Unlock() - - r.maybeAdjustFirstPacketTime(ets) -} - -func (r *RTPStats) maybeAdjustFirstPacketTime(ets uint64) { - if time.Since(r.startTime) > firstPacketTimeAdjustWindow { - return - } - - // for some time after the start, adjust time of first packet. - // Helps improve accuracy of expected timestamp calculation. - // Adjusting only one way, i. e. if the first sample experienced - // 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. - samplesDiff := int64(ets - r.timestamp.GetExtendedStart()) - if samplesDiff < 0 { - // out-of-order, skip - return - } - samplesDuration := time.Duration(float64(samplesDiff) / float64(r.params.ClockRate) * float64(time.Second)) - now := time.Now() - firstTime := now.Add(-samplesDuration) - if firstTime.Before(r.firstTime) { - r.logger.Debugw( - "adjusting first packet time", - "startTime", r.startTime.String(), - "nowTime", now.String(), - "before", r.firstTime.String(), - "after", firstTime.String(), - "adjustment", r.firstTime.Sub(firstTime), - "extNowTS", ets, - "extStartTS", r.timestamp.GetExtendedStart(), - ) - if r.firstTime.Sub(firstTime) > firstPacketTimeAdjustThreshold { - r.logger.Infow("first packet time adjustment too big, ignoring", - "startTime", r.startTime.String(), - "nowTime", now.String(), - "before", r.firstTime.String(), - "after", firstTime.String(), - "adjustment", r.firstTime.Sub(firstTime), - "extNowTS", ets, - "extStartTS", r.timestamp.GetExtendedStart(), - ) - } else { - r.firstTime = firstTime - } - } -} - -func (r *RTPStats) SetRtcpSenderReportData(srData *RTCPSenderReportData) { - r.lock.Lock() - defer r.lock.Unlock() - - if srData == nil || !r.initialized { - return - } - - // prevent against extreme case of anachronous sender reports - if r.srNewest != nil && r.srNewest.NTPTimestamp > srData.NTPTimestamp { - r.logger.Infow( - "received anachronous sender report", - "currentNTP", srData.NTPTimestamp.Time().String(), - "currentRTP", srData.RTPTimestamp, - "currentAt", srData.At.String(), - "lastNTP", r.srNewest.NTPTimestamp.Time().String(), - "lastRTP", r.srNewest.RTPTimestamp, - "lastAt", r.srNewest.At.String(), - ) - return - } - - tsCycles := uint64(0) - pcCycles := uint64(0) - if r.srNewest != nil { - tsCycles = r.srNewest.RTPTimestampExt & 0xFFFF_FFFF_0000_0000 - if (srData.RTPTimestamp-r.srNewest.RTPTimestamp) < (1<<31) && srData.RTPTimestamp < r.srNewest.RTPTimestamp { - tsCycles += (1 << 32) - } - - pcCycles = r.srNewest.PacketCountExt & 0xFFFF_FFFF_0000_0000 - if (srData.PacketCount-r.srNewest.PacketCount) < (1<<31) && srData.PacketCount < r.srNewest.PacketCount { - pcCycles += (1 << 32) - } - } - - srDataCopy := *srData - srDataCopy.RTPTimestampExt = uint64(srDataCopy.RTPTimestamp) + tsCycles - srDataCopy.PacketCountExt = uint64(srDataCopy.PacketCount) + pcCycles - - r.maybeAdjustFirstPacketTime(srDataCopy.RTPTimestampExt) - - if r.srNewest != nil && srDataCopy.RTPTimestampExt < r.srNewest.RTPTimestampExt { - // This can happen when a track is replaced with a null and then restored - - // i. e. muting replacing with null and unmute restoring the original track. - // Under such a condition reset the sender reports to start from this point. - // Resetting will ensure sample rate calculations do not go haywire due to negative time. - r.logger.Infow( - "received sender report, out-of-order, resetting", - "prevTSExt", r.srNewest.RTPTimestampExt, - "prevRTP", r.srNewest.RTPTimestamp, - "prevNTP", r.srNewest.NTPTimestamp.Time().String(), - "prevAt", r.srNewest.At.String(), - "currTSExt", srDataCopy.RTPTimestampExt, - "currRTP", srDataCopy.RTPTimestamp, - "currNTP", srDataCopy.NTPTimestamp.Time().String(), - "currentAt", srDataCopy.At.String(), - ) - r.srFirst = nil - } - - r.srNewest = &srDataCopy - if r.srFirst == nil { - r.srFirst = &srDataCopy - } -} - -func (r *RTPStats) GetRtcpSenderReportData() (srFirst *RTCPSenderReportData, srNewest *RTCPSenderReportData) { - r.lock.RLock() - defer r.lock.RUnlock() - - if r.srFirst != nil { - srFirstCopy := *r.srFirst - srFirst = &srFirstCopy - } - - if r.srNewest != nil { - srNewestCopy := *r.srNewest - srNewest = &srNewestCopy - } - return -} - -func (r *RTPStats) GetExpectedRTPTimestamp(at time.Time) (expectedTSExt uint64, err error) { - r.lock.RLock() - defer r.lock.RUnlock() - - if !r.initialized { - err = errors.New("uninitilaized") - return - } - - timeDiff := at.Sub(r.firstTime) - expectedRTPDiff := timeDiff.Nanoseconds() * int64(r.params.ClockRate) / 1e9 - expectedTSExt = r.timestamp.GetExtendedStart() + uint64(expectedRTPDiff) - return -} - -func (r *RTPStats) GetRtcpSenderReport(ssrc uint32, calculatedClockRate uint32) *rtcp.SenderReport { - r.lock.Lock() - defer r.lock.Unlock() - - if !r.initialized { - return nil - } - - // construct current time based on monotonic clock - timeSinceFirst := time.Since(r.firstTime) - now := r.firstTime.Add(timeSinceFirst) - nowNTP := mediatransportutil.ToNtpTime(now) - - timeSinceHighest := now.Sub(r.highestTime) - nowRTPExt := r.timestamp.GetExtendedHighest() + uint64(timeSinceHighest.Nanoseconds()*int64(r.params.ClockRate)/1e9) - nowRTPExtUsingTime := nowRTPExt - nowRTP := uint32(nowRTPExt) - - // It is possible that publisher is pacing at a slower rate. - // That would make `highestTS` to be lagging the RTP time stamp in the RTCP Sender Report from publisher. - // Check for that using calculated clock rate and use the later time stamp if applicable. - var nowRTPExtUsingRate uint64 - if calculatedClockRate != 0 { - nowRTPExtUsingRate = r.timestamp.GetExtendedStart() + uint64(float64(calculatedClockRate)*timeSinceFirst.Seconds()) - if nowRTPExtUsingRate > nowRTPExt { - nowRTPExt = nowRTPExtUsingRate - nowRTP = uint32(nowRTPExt) - } - } - - if r.srNewest != nil && nowRTPExt < r.srNewest.RTPTimestampExt { - // If report being generated is behind, use the time difference and - // clock rate of codec to produce next report. - // - // Current report could be behind due to the following - // - Publisher pacing - // - Due to above, report from publisher side is ahead of packet timestamps. - // Note that report will map wall clock to timestamp at capture time and happens before the pacer. - // - Pause/Mute followed by resume, some combination of events that could - // result in this module not having calculated clock rate of publisher side. - // - When the above happens, current will be generated using highestTS which could be behind. - // That could end up behind the last report's timestamp in extreme cases - r.logger.Infow( - "sending sender report, out-of-order, repairing", - "prevTSExt", r.srNewest.RTPTimestampExt, - "prevRTP", r.srNewest.RTPTimestamp, - "prevNTP", r.srNewest.NTPTimestamp.Time().String(), - "currTSExt", nowRTPExt, - "currRTP", nowRTP, - "currNTP", nowNTP.Time().String(), - "timeNow", time.Now().String(), - "firstTime", r.firstTime.String(), - "timeSinceFirst", timeSinceFirst, - "highestTime", r.highestTime.String(), - "timeSinceHighest", timeSinceHighest, - "nowRTPExtUsingTime", nowRTPExtUsingTime, - "calculatedClockRate", calculatedClockRate, - "nowRTPExtUsingRate", nowRTPExtUsingRate, - ) - ntpDiffSinceLast := nowNTP.Time().Sub(r.srNewest.NTPTimestamp.Time()) - nowRTPExt = r.srNewest.RTPTimestampExt + uint64(ntpDiffSinceLast.Seconds()*float64(r.params.ClockRate)) - nowRTP = uint32(nowRTPExt) - } - - r.srNewest = &RTCPSenderReportData{ - NTPTimestamp: nowNTP, - RTPTimestamp: nowRTP, - RTPTimestampExt: nowRTPExt, - At: now, - } - if r.srFirst == nil { - r.srFirst = r.srNewest - } - - return &rtcp.SenderReport{ - SSRC: ssrc, - NTPTime: uint64(nowNTP), - RTPTime: nowRTP, - PacketCount: uint32(r.getTotalPacketsPrimary() + r.packetsDuplicate + r.packetsPadding), - OctetCount: uint32(r.bytes + r.bytesDuplicate + r.bytesPadding), - } -} - -func (r *RTPStats) SnapshotRtcpReceptionReport(ssrc uint32, proxyFracLost uint8, snapshotId uint32) *rtcp.ReceptionReport { - r.lock.Lock() - then, now := r.getAndResetSnapshot(snapshotId, false) - r.lock.Unlock() - - if now == nil || then == nil { - return nil - } - - r.lock.RLock() - defer r.lock.RUnlock() - - packetsExpected := now.extStartSN - then.extStartSN - if packetsExpected > NumSequenceNumbers { - r.logger.Warnw( - "too many packets expected in receiver report", - fmt.Errorf("start: %d, end: %d, expected: %d", then.extStartSN, now.extStartSN, packetsExpected), - ) - return nil - } - if packetsExpected == 0 { - return nil - } - - intervalStats := r.getIntervalStats(then.extStartSN, now.extStartSN) - packetsLost := intervalStats.packetsLost - lossRate := float32(packetsLost) / float32(packetsExpected) - fracLost := uint8(lossRate * 256.0) - if proxyFracLost > fracLost { - fracLost = proxyFracLost - } - - lastSR := uint32(0) - dlsr := uint32(0) - if r.srNewest != nil { - lastSR = uint32(r.srNewest.NTPTimestamp >> 16) - if !r.srNewest.At.IsZero() { - delayMS := uint32(time.Since(r.srNewest.At).Milliseconds()) - dlsr = (delayMS / 1e3) << 16 - dlsr |= (delayMS % 1e3) * 65536 / 1000 - } - } - - return &rtcp.ReceptionReport{ - SSRC: ssrc, - FractionLost: fracLost, - TotalLost: uint32(r.packetsLost), - LastSequenceNumber: uint32(now.extStartSN), - Jitter: uint32(r.jitter), - LastSenderReport: lastSR, - Delay: dlsr, - } -} - -func (r *RTPStats) DeltaInfo(snapshotId uint32) *RTPDeltaInfo { - r.lock.Lock() - then, now := r.getAndResetSnapshot(snapshotId, false) - r.lock.Unlock() - - if now == nil || then == nil { - return nil - } - - r.lock.RLock() - defer r.lock.RUnlock() - - startTime := then.startTime - endTime := now.startTime - - packetsExpected := now.extStartSN - then.extStartSN - if packetsExpected > NumSequenceNumbers { - r.logger.Errorw( - "too many packets expected in delta", - fmt.Errorf("start: %d, end: %d, expected: %d", then.extStartSN, now.extStartSN, packetsExpected), - ) - return nil - } - if packetsExpected == 0 { - return &RTPDeltaInfo{ - StartTime: startTime, - Duration: endTime.Sub(startTime), - } - } - - intervalStats := r.getIntervalStats(then.extStartSN, now.extStartSN) - return &RTPDeltaInfo{ - StartTime: startTime, - Duration: endTime.Sub(startTime), - Packets: uint32(packetsExpected - intervalStats.packetsPadding), - Bytes: intervalStats.bytes, - HeaderBytes: intervalStats.headerBytes, - PacketsDuplicate: uint32(now.packetsDuplicate - then.packetsDuplicate), - BytesDuplicate: now.bytesDuplicate - then.bytesDuplicate, - HeaderBytesDuplicate: now.headerBytesDuplicate - then.headerBytesDuplicate, - PacketsPadding: uint32(intervalStats.packetsPadding), - BytesPadding: intervalStats.bytesPadding, - HeaderBytesPadding: intervalStats.headerBytesPadding, - PacketsLost: uint32(intervalStats.packetsLost), - Frames: intervalStats.frames, - RttMax: then.maxRtt, - JitterMax: then.maxJitter / float64(r.params.ClockRate) * 1e6, - Nacks: now.nacks - then.nacks, - Plis: now.plis - then.plis, - Firs: now.firs - then.firs, - } -} - -func (r *RTPStats) DeltaInfoOverridden(snapshotId uint32) *RTPDeltaInfo { - if !r.params.IsReceiverReportDriven || r.lastRRTime.IsZero() { - return nil - } - - r.lock.Lock() - then, now := r.getAndResetSnapshot(snapshotId, true) - r.lock.Unlock() - - if now == nil || then == nil { - return nil - } - - r.lock.RLock() - defer r.lock.RUnlock() - - startTime := then.startTime - endTime := now.startTime - - packetsExpected := now.extStartSNOverridden - then.extStartSNOverridden - if packetsExpected > NumSequenceNumbers { - r.logger.Warnw( - "too many packets expected in delta (overridden)", - fmt.Errorf("start: %d, end: %d, expected: %d", then.extStartSNOverridden, now.extStartSNOverridden, packetsExpected), - ) - return nil - } - if packetsExpected == 0 { - // not received RTCP RR (OR) publisher is not producing any data - return nil - } - - intervalStats := r.getIntervalStats(then.extStartSNOverridden, now.extStartSNOverridden) - packetsLost := now.packetsLostOverridden - then.packetsLostOverridden - if int32(packetsLost) < 0 { - packetsLost = 0 - } - - if packetsLost > packetsExpected { - r.logger.Warnw( - "unexpected number of packets lost", - fmt.Errorf( - "start: %d, end: %d, expected: %d, lost: report: %d, interval: %d", - then.extStartSNOverridden, - now.extStartSNOverridden, - packetsExpected, - now.packetsLostOverridden-then.packetsLostOverridden, - intervalStats.packetsLost, - ), - ) - packetsLost = packetsExpected - } - - // discount jitter from publisher side + internal processing - maxJitter := then.maxJitterOverridden - then.maxJitter - if maxJitter < 0.0 { - maxJitter = 0.0 - } - maxJitterTime := maxJitter / float64(r.params.ClockRate) * 1e6 - - return &RTPDeltaInfo{ - StartTime: startTime, - Duration: endTime.Sub(startTime), - Packets: uint32(packetsExpected - intervalStats.packetsPadding), - Bytes: intervalStats.bytes, - HeaderBytes: intervalStats.headerBytes, - PacketsDuplicate: uint32(now.packetsDuplicate - then.packetsDuplicate), - BytesDuplicate: now.bytesDuplicate - then.bytesDuplicate, - HeaderBytesDuplicate: now.headerBytesDuplicate - then.headerBytesDuplicate, - PacketsPadding: uint32(intervalStats.packetsPadding), - BytesPadding: intervalStats.bytesPadding, - HeaderBytesPadding: intervalStats.headerBytesPadding, - PacketsLost: uint32(packetsLost), - PacketsMissing: uint32(intervalStats.packetsLost), - PacketsOutOfOrder: uint32(intervalStats.packetsOutOfOrder), - Frames: intervalStats.frames, - RttMax: then.maxRtt, - JitterMax: maxJitterTime, - Nacks: now.nacks - then.nacks, - Plis: now.plis - then.plis, - Firs: now.firs - then.firs, - } -} - -func (r *RTPStats) ToString() string { - p := r.ToProto() - if p == nil { - return "" - } - - r.lock.RLock() - defer r.lock.RUnlock() - - expectedPackets := r.getPacketsExpected() - expectedPacketRate := float64(expectedPackets) / p.Duration - - str := fmt.Sprintf("t: %+v|%+v|%.2fs", p.StartTime.AsTime().Format(time.UnixDate), p.EndTime.AsTime().Format(time.UnixDate), p.Duration) - - str += fmt.Sprintf(", sn: %d|%d", r.sequenceNumber.GetExtendedStart(), r.sequenceNumber.GetExtendedHighest()) - str += fmt.Sprintf(", ep: %d|%.2f/s", expectedPackets, expectedPacketRate) - - str += fmt.Sprintf(", p: %d|%.2f/s", p.Packets, p.PacketRate) - str += fmt.Sprintf(", l: %d|%.1f/s|%.2f%%", p.PacketsLost, p.PacketLossRate, p.PacketLossPercentage) - str += fmt.Sprintf(", b: %d|%.1fbps|%d", p.Bytes, p.Bitrate, p.HeaderBytes) - str += fmt.Sprintf(", f: %d|%.1f/s / %d|%+v", p.Frames, p.FrameRate, p.KeyFrames, p.LastKeyFrame.AsTime().Format(time.UnixDate)) - - str += fmt.Sprintf(", d: %d|%.2f/s", p.PacketsDuplicate, p.PacketDuplicateRate) - str += fmt.Sprintf(", bd: %d|%.1fbps|%d", p.BytesDuplicate, p.BitrateDuplicate, p.HeaderBytesDuplicate) - - str += fmt.Sprintf(", pp: %d|%.2f/s", p.PacketsPadding, p.PacketPaddingRate) - str += fmt.Sprintf(", bp: %d|%.1fbps|%d", p.BytesPadding, p.BitratePadding, p.HeaderBytesPadding) - - str += fmt.Sprintf(", o: %d", p.PacketsOutOfOrder) - - jitter := r.jitter - maxJitter := r.maxJitter - if r.params.IsReceiverReportDriven { - // NOTE: jitter includes jitter from publisher and from processing - jitter = r.jitterOverridden - maxJitter = r.maxJitterOverridden - } - str += fmt.Sprintf(", c: %d, j: %d(%.1fus)|%d(%.1fus)", r.params.ClockRate, uint32(jitter), p.JitterCurrent, uint32(maxJitter), p.JitterMax) - - if len(p.GapHistogram) != 0 { - first := true - str += ", gh:[" - for burst, count := range p.GapHistogram { - if !first { - str += ", " - } - first = false - str += fmt.Sprintf("%d:%d", burst, count) - } - str += "]" - } - - str += ", n:" - str += fmt.Sprintf("%d|%d|%d|%d", p.Nacks, p.NackAcks, p.NackMisses, p.NackRepeated) - - str += ", pli:" - str += fmt.Sprintf("%d|%+v / %d|%+v", - p.Plis, p.LastPli.AsTime().Format(time.UnixDate), - p.LayerLockPlis, p.LastLayerLockPli.AsTime().Format(time.UnixDate), - ) - - str += ", fir:" - str += fmt.Sprintf("%d|%+v", p.Firs, p.LastFir.AsTime().Format(time.UnixDate)) - - str += ", rtt(ms):" - str += fmt.Sprintf("%d|%d", p.RttCurrent, p.RttMax) - - str += fmt.Sprintf(", pd: %s, rd: %s", RTPDriftToString(p.PacketDrift), RTPDriftToString(p.ReportDrift)) - return str -} - -func (r *RTPStats) ToProto() *livekit.RTPStats { - r.lock.RLock() - defer r.lock.RUnlock() - - if r.startTime.IsZero() { - return nil - } - - endTime := r.endTime - if endTime.IsZero() { - endTime = time.Now() - } - elapsed := endTime.Sub(r.startTime).Seconds() - if elapsed == 0.0 { - return nil - } - - packets := r.getTotalPacketsPrimary() - packetRate := float64(packets) / elapsed - bitrate := float64(r.bytes) * 8.0 / elapsed - - frameRate := float64(r.frames) / elapsed - - packetsExpected := r.getPacketsExpected() - packetsLost := r.getPacketsLost() - packetLostRate := float64(packetsLost) / elapsed - packetLostPercentage := float32(packetsLost) / float32(packetsExpected) * 100.0 - - packetDuplicateRate := float64(r.packetsDuplicate) / elapsed - bitrateDuplicate := float64(r.bytesDuplicate) * 8.0 / elapsed - - packetPaddingRate := float64(r.packetsPadding) / elapsed - bitratePadding := float64(r.bytesPadding) * 8.0 / elapsed - - jitter := r.jitter - maxJitter := r.maxJitter - if r.params.IsReceiverReportDriven { - // NOTE: jitter includes jitter from publisher and from processing - jitter = r.jitterOverridden - maxJitter = r.maxJitterOverridden - } - jitterTime := jitter / float64(r.params.ClockRate) * 1e6 - maxJitterTime := maxJitter / float64(r.params.ClockRate) * 1e6 - - packetDrift, reportDrift := r.getDrift() - - p := &livekit.RTPStats{ - StartTime: timestamppb.New(r.startTime), - EndTime: timestamppb.New(endTime), - Duration: elapsed, - Packets: uint32(packets), - PacketRate: packetRate, - Bytes: r.bytes, - HeaderBytes: r.headerBytes, - Bitrate: bitrate, - PacketsLost: uint32(packetsLost), - PacketLossRate: packetLostRate, - PacketLossPercentage: packetLostPercentage, - PacketsDuplicate: uint32(r.packetsDuplicate), - PacketDuplicateRate: packetDuplicateRate, - BytesDuplicate: r.bytesDuplicate, - HeaderBytesDuplicate: r.headerBytesDuplicate, - BitrateDuplicate: bitrateDuplicate, - PacketsPadding: uint32(r.packetsPadding), - PacketPaddingRate: packetPaddingRate, - BytesPadding: r.bytesPadding, - HeaderBytesPadding: r.headerBytesPadding, - BitratePadding: bitratePadding, - PacketsOutOfOrder: uint32(r.packetsOutOfOrder), - Frames: r.frames, - FrameRate: frameRate, - KeyFrames: r.keyFrames, - LastKeyFrame: timestamppb.New(r.lastKeyFrame), - JitterCurrent: jitterTime, - JitterMax: maxJitterTime, - Nacks: r.nacks, - NackAcks: r.nackAcks, - NackMisses: r.nackMisses, - NackRepeated: r.nackRepeated, - Plis: r.plis, - LastPli: timestamppb.New(r.lastPli), - LayerLockPlis: r.layerLockPlis, - LastLayerLockPli: timestamppb.New(r.lastLayerLockPli), - Firs: r.firs, - LastFir: timestamppb.New(r.lastFir), - RttCurrent: r.rtt, - RttMax: r.maxRtt, - PacketDrift: packetDrift, - ReportDrift: reportDrift, - } - - gapsPresent := false - for i := 0; i < len(r.gapHistogram); i++ { - if r.gapHistogram[i] == 0 { - continue - } - - gapsPresent = true - break - } - - if gapsPresent { - p.GapHistogram = make(map[int32]uint32, GapHistogramNumBins) - for i := 0; i < len(r.gapHistogram); i++ { - if r.gapHistogram[i] == 0 { - continue - } - - p.GapHistogram[int32(i+1)] = r.gapHistogram[i] - } - } - - return p -} - -func (r *RTPStats) getExtHighestSNAdjusted() uint64 { - if r.params.IsReceiverReportDriven && !r.lastRRTime.IsZero() { - return r.extHighestSNOverridden - } - - return r.sequenceNumber.GetExtendedHighest() -} - -func (r *RTPStats) getPacketsLost() uint64 { - if r.params.IsReceiverReportDriven && !r.lastRRTime.IsZero() { - return r.packetsLostOverridden - } - - return r.packetsLost -} - -func (r *RTPStats) getSnInfoOutOfOrderPtr(esn uint64, ehsn uint64) int { - offset := int64(ehsn - esn) - if offset >= SnInfoSize || offset < 0 { - // too old OR too new (i. e. ahead of highest) - return -1 - } - - return int(esn & SnInfoMask) -} - -func (r *RTPStats) setSnInfo(esn uint64, ehsn uint64, pktSize uint16, hdrSize uint16, payloadSize uint16, marker bool, isOutOfOrder bool) { - slot := 0 - if int64(esn-ehsn) < 0 { - slot = r.getSnInfoOutOfOrderPtr(esn, ehsn) - if slot < 0 { - return - } - } else { - slot = int(esn & SnInfoMask) - } - - snInfo := &r.snInfos[slot] - snInfo.pktSize = pktSize - snInfo.hdrSize = hdrSize - snInfo.isPaddingOnly = payloadSize == 0 - snInfo.marker = marker - snInfo.isOutOfOrder = isOutOfOrder -} - -func (r *RTPStats) clearSnInfos(extStartInclusive uint64, extEndExclusive uint64) { - for esn := extStartInclusive; esn != extEndExclusive; esn++ { - snInfo := &r.snInfos[esn&SnInfoMask] - snInfo.pktSize = 0 - snInfo.hdrSize = 0 - snInfo.isPaddingOnly = false - snInfo.marker = false - } -} - -func (r *RTPStats) isSnInfoLost(esn uint64, ehsn uint64) bool { - slot := r.getSnInfoOutOfOrderPtr(esn, ehsn) - if slot < 0 { - return false - } - - return r.snInfos[slot].pktSize == 0 -} - -func (r *RTPStats) getIntervalStats(extStartInclusive uint64, extEndExclusive uint64) (intervalStats IntervalStats) { - packetsNotFound := uint32(0) - processESN := func(esn uint64, ehsn uint64) { - slot := r.getSnInfoOutOfOrderPtr(esn, ehsn) - if slot < 0 { - packetsNotFound++ - return - } - - snInfo := &r.snInfos[slot] - switch { - case snInfo.pktSize == 0: - intervalStats.packetsLost++ - - case snInfo.isPaddingOnly: - intervalStats.packetsPadding++ - intervalStats.bytesPadding += uint64(snInfo.pktSize) - intervalStats.headerBytesPadding += uint64(snInfo.hdrSize) - - default: - intervalStats.packets++ - intervalStats.bytes += uint64(snInfo.pktSize) - intervalStats.headerBytes += uint64(snInfo.hdrSize) - if snInfo.isOutOfOrder { - intervalStats.packetsOutOfOrder++ - } - } - - if snInfo.marker { - intervalStats.frames++ - } - } - - ehsn := r.sequenceNumber.GetExtendedHighest() - for esn := extStartInclusive; esn != extEndExclusive; esn++ { - processESN(esn, ehsn) - } - - if packetsNotFound != 0 { - r.logger.Errorw( - "could not find some packets", nil, - "start", extStartInclusive, - "end", extEndExclusive, - "count", packetsNotFound, - "highestSN", r.sequenceNumber.GetExtendedHighest(), - ) - } - return -} - -func (r *RTPStats) updateJitter(rtph *rtp.Header, packetTime time.Time) { - // Do not update jitter on multiple packets of same frame. - // All packets of a frame have the same time stamp. - // NOTE: This does not protect against using more than one packet of the same frame - // if packets arrive out-of-order. For example, - // p1f1 -> p1f2 -> p2f1 - // In this case, p2f1 (packet 2, frame 1) will still be used in jitter calculation - // although it is the second packet of a frame because of out-of-order receival. - if r.lastJitterRTP == rtph.Timestamp { - return - } - - timeSinceFirst := packetTime.Sub(r.firstTime) - packetTimeRTP := uint32(timeSinceFirst.Nanoseconds() * int64(r.params.ClockRate) / 1e9) - transit := packetTimeRTP - rtph.Timestamp - - if r.lastTransit != 0 { - d := int32(transit - r.lastTransit) - if d < 0 { - d = -d - } - r.jitter += (float64(d) - r.jitter) / 16 - if r.jitter > r.maxJitter { - r.maxJitter = r.jitter - } - - for _, s := range r.snapshots { - if r.jitter > s.maxJitter { - s.maxJitter = r.jitter - } - } - } - - r.lastTransit = transit - r.lastJitterRTP = rtph.Timestamp -} - -func (r *RTPStats) getDrift() (packetDrift *livekit.RTPDrift, reportDrift *livekit.RTPDrift) { - if !r.firstTime.IsZero() { - elapsed := r.highestTime.Sub(r.firstTime) - rtpClockTicks := r.timestamp.GetExtendedHighest() - r.timestamp.GetExtendedStart() - driftSamples := int64(rtpClockTicks - uint64(elapsed.Nanoseconds()*int64(r.params.ClockRate)/1e9)) - if elapsed.Seconds() > 0.0 { - packetDrift = &livekit.RTPDrift{ - StartTime: timestamppb.New(r.firstTime), - EndTime: timestamppb.New(r.highestTime), - Duration: elapsed.Seconds(), - StartTimestamp: r.timestamp.GetExtendedStart(), - EndTimestamp: r.timestamp.GetExtendedHighest(), - RtpClockTicks: rtpClockTicks, - DriftSamples: driftSamples, - DriftMs: (float64(driftSamples) * 1000) / float64(r.params.ClockRate), - ClockRate: float64(rtpClockTicks) / elapsed.Seconds(), - } - } - } - - if r.srFirst != nil && r.srNewest != nil && r.srFirst.RTPTimestamp != r.srNewest.RTPTimestamp { - elapsed := r.srNewest.NTPTimestamp.Time().Sub(r.srFirst.NTPTimestamp.Time()) - rtpClockTicks := r.srNewest.RTPTimestampExt - r.srFirst.RTPTimestampExt - driftSamples := int64(rtpClockTicks - uint64(elapsed.Nanoseconds()*int64(r.params.ClockRate)/1e9)) - if elapsed.Seconds() > 0.0 { - reportDrift = &livekit.RTPDrift{ - StartTime: timestamppb.New(r.srFirst.NTPTimestamp.Time()), - EndTime: timestamppb.New(r.srNewest.NTPTimestamp.Time()), - Duration: elapsed.Seconds(), - StartTimestamp: r.srFirst.RTPTimestampExt, - EndTimestamp: r.srNewest.RTPTimestampExt, - RtpClockTicks: rtpClockTicks, - DriftSamples: driftSamples, - DriftMs: (float64(driftSamples) * 1000) / float64(r.params.ClockRate), - ClockRate: float64(rtpClockTicks) / elapsed.Seconds(), - } - } - } - return -} - -func (r *RTPStats) updateGapHistogram(gap int) { - if gap < 2 { - return - } - - missing := gap - 1 - if missing > len(r.gapHistogram) { - r.gapHistogram[len(r.gapHistogram)-1]++ - } else { - r.gapHistogram[missing-1]++ - } -} - -func (r *RTPStats) getAndResetSnapshot(snapshotId uint32, override bool) (*Snapshot, *Snapshot) { - if !r.initialized || (override && r.lastRRTime.IsZero()) { - return nil, nil - } - - then := r.snapshots[snapshotId] - if then == nil { - extStartSN := r.sequenceNumber.GetExtendedStart() - then = &Snapshot{ - startTime: r.startTime, - extStartSN: extStartSN, - extStartSNOverridden: extStartSN, - } - r.snapshots[snapshotId] = then - } - - var startTime time.Time - if override { - startTime = r.lastRRTime - } else { - startTime = time.Now() - } - - // snapshot now - r.snapshots[snapshotId] = &Snapshot{ - startTime: startTime, - extStartSN: r.sequenceNumber.GetExtendedHighest() + 1, - extStartSNOverridden: r.getExtHighestSNAdjusted() + 1, - packetsDuplicate: r.packetsDuplicate, - bytesDuplicate: r.bytesDuplicate, - headerBytesDuplicate: r.headerBytesDuplicate, - packetsLostOverridden: r.packetsLostOverridden, - nacks: r.nacks, - plis: r.plis, - firs: r.firs, - maxJitter: r.jitter, - maxJitterOverridden: r.jitterOverridden, - maxRtt: r.rtt, - } - // make a copy so that it can be used independently - now := *r.snapshots[snapshotId] - - return then, &now -} - -// ---------------------------------- - -func AggregateRTPStats(statsList []*livekit.RTPStats) *livekit.RTPStats { - if len(statsList) == 0 { - return nil - } - - startTime := time.Time{} - endTime := time.Time{} - - packets := uint32(0) - bytes := uint64(0) - headerBytes := uint64(0) - packetsLost := uint32(0) - packetsDuplicate := uint32(0) - bytesDuplicate := uint64(0) - headerBytesDuplicate := uint64(0) - packetsPadding := uint32(0) - bytesPadding := uint64(0) - headerBytesPadding := uint64(0) - packetsOutOfOrder := uint32(0) - frames := uint32(0) - keyFrames := uint32(0) - lastKeyFrame := time.Time{} - jitter := 0.0 - maxJitter := float64(0) - gapHistogram := make(map[int32]uint32, GapHistogramNumBins) - nacks := uint32(0) - nackAcks := uint32(0) - nackMisses := uint32(0) - nackRepeated := uint32(0) - plis := uint32(0) - lastPli := time.Time{} - layerLockPlis := uint32(0) - lastLayerLockPli := time.Time{} - firs := uint32(0) - lastFir := time.Time{} - rtt := uint32(0) - maxRtt := uint32(0) - - for _, stats := range statsList { - if startTime.IsZero() || startTime.After(stats.StartTime.AsTime()) { - startTime = stats.StartTime.AsTime() - } - - if endTime.IsZero() || endTime.Before(stats.EndTime.AsTime()) { - endTime = stats.EndTime.AsTime() - } - - packets += stats.Packets - bytes += stats.Bytes - headerBytes += stats.HeaderBytes - - packetsLost += stats.PacketsLost - - packetsDuplicate += stats.PacketsDuplicate - bytesDuplicate += stats.BytesDuplicate - headerBytesDuplicate += stats.HeaderBytesDuplicate - - packetsPadding += stats.PacketsPadding - bytesPadding += stats.BytesPadding - headerBytesPadding += stats.HeaderBytesPadding - - packetsOutOfOrder += stats.PacketsOutOfOrder - - frames += stats.Frames - - keyFrames += stats.KeyFrames - if lastKeyFrame.IsZero() || lastKeyFrame.Before(stats.LastKeyFrame.AsTime()) { - lastKeyFrame = stats.LastKeyFrame.AsTime() - } - - jitter += stats.JitterCurrent - if stats.JitterMax > maxJitter { - maxJitter = stats.JitterMax - } - - for burst, count := range stats.GapHistogram { - gapHistogram[burst] += count - } - - nacks += stats.Nacks - nackAcks += stats.NackAcks - nackMisses += stats.NackMisses - nackRepeated += stats.NackRepeated - - plis += stats.Plis - if lastPli.IsZero() || lastPli.Before(stats.LastPli.AsTime()) { - lastPli = stats.LastPli.AsTime() - } - - layerLockPlis += stats.LayerLockPlis - if lastLayerLockPli.IsZero() || lastLayerLockPli.Before(stats.LastLayerLockPli.AsTime()) { - lastLayerLockPli = stats.LastLayerLockPli.AsTime() - } - - firs += stats.Firs - if lastFir.IsZero() || lastPli.Before(stats.LastFir.AsTime()) { - lastFir = stats.LastFir.AsTime() - } - - rtt += stats.RttCurrent - if stats.RttMax > maxRtt { - maxRtt = stats.RttMax - } - } - - if endTime.IsZero() { - endTime = time.Now() - } - elapsed := endTime.Sub(startTime).Seconds() - - packetLostRate := float64(packetsLost) / elapsed - packetLostPercentage := float32(packetsLost) / (float32(packets) + float32(packetsLost)) * 100.0 - - packetRate := float64(packets) / elapsed - packetDuplicateRate := float64(packetsDuplicate) / elapsed - packetPaddingRate := float64(packetsPadding) / elapsed - - bitrate := float64(bytes) * 8.0 / elapsed - bitrateDuplicate := float64(bytesDuplicate) * 8.0 / elapsed - bitratePadding := float64(bytesPadding) * 8.0 / elapsed - - frameRate := float64(frames) / elapsed - - return &livekit.RTPStats{ - StartTime: timestamppb.New(startTime), - EndTime: timestamppb.New(endTime), - Duration: elapsed, - Packets: packets, - PacketRate: packetRate, - Bytes: bytes, - HeaderBytes: headerBytes, - Bitrate: bitrate, - PacketsLost: packetsLost, - PacketLossRate: packetLostRate, - PacketLossPercentage: packetLostPercentage, - PacketsDuplicate: packetsDuplicate, - PacketDuplicateRate: packetDuplicateRate, - BytesDuplicate: bytesDuplicate, - HeaderBytesDuplicate: headerBytesDuplicate, - BitrateDuplicate: bitrateDuplicate, - PacketsPadding: packetsPadding, - PacketPaddingRate: packetPaddingRate, - BytesPadding: bytesPadding, - HeaderBytesPadding: headerBytesPadding, - BitratePadding: bitratePadding, - PacketsOutOfOrder: packetsOutOfOrder, - Frames: frames, - FrameRate: frameRate, - KeyFrames: keyFrames, - LastKeyFrame: timestamppb.New(lastKeyFrame), - JitterCurrent: jitter / float64(len(statsList)), - JitterMax: maxJitter, - GapHistogram: gapHistogram, - Nacks: nacks, - NackAcks: nackAcks, - NackMisses: nackMisses, - NackRepeated: nackRepeated, - Plis: plis, - LastPli: timestamppb.New(lastPli), - LayerLockPlis: layerLockPlis, - LastLayerLockPli: timestamppb.New(lastLayerLockPli), - Firs: firs, - LastFir: timestamppb.New(lastFir), - RttCurrent: rtt / uint32(len(statsList)), - RttMax: maxRtt, - // no aggregation for drift calculations - } -} - -func AggregateRTPDeltaInfo(deltaInfoList []*RTPDeltaInfo) *RTPDeltaInfo { - if len(deltaInfoList) == 0 { - return nil - } - - startTime := time.Time{} - endTime := time.Time{} - - packets := uint32(0) - bytes := uint64(0) - headerBytes := uint64(0) - - packetsDuplicate := uint32(0) - bytesDuplicate := uint64(0) - headerBytesDuplicate := uint64(0) - - packetsPadding := uint32(0) - bytesPadding := uint64(0) - headerBytesPadding := uint64(0) - - packetsLost := uint32(0) - packetsMissing := uint32(0) - packetsOutOfOrder := uint32(0) - - frames := uint32(0) - - maxRtt := uint32(0) - maxJitter := float64(0) - - nacks := uint32(0) - plis := uint32(0) - firs := uint32(0) - - for _, deltaInfo := range deltaInfoList { - if deltaInfo == nil { - continue - } - - if startTime.IsZero() || startTime.After(deltaInfo.StartTime) { - startTime = deltaInfo.StartTime - } - - endedAt := deltaInfo.StartTime.Add(deltaInfo.Duration) - if endTime.IsZero() || endTime.Before(endedAt) { - endTime = endedAt - } - - packets += deltaInfo.Packets - bytes += deltaInfo.Bytes - headerBytes += deltaInfo.HeaderBytes - - packetsDuplicate += deltaInfo.PacketsDuplicate - bytesDuplicate += deltaInfo.BytesDuplicate - headerBytesDuplicate += deltaInfo.HeaderBytesDuplicate - - packetsPadding += deltaInfo.PacketsPadding - bytesPadding += deltaInfo.BytesPadding - headerBytesPadding += deltaInfo.HeaderBytesPadding - - packetsLost += deltaInfo.PacketsLost - packetsMissing += deltaInfo.PacketsMissing - packetsOutOfOrder += deltaInfo.PacketsOutOfOrder - - frames += deltaInfo.Frames - - if deltaInfo.RttMax > maxRtt { - maxRtt = deltaInfo.RttMax - } - - if deltaInfo.JitterMax > maxJitter { - maxJitter = deltaInfo.JitterMax - } - - nacks += deltaInfo.Nacks - plis += deltaInfo.Plis - firs += deltaInfo.Firs - } - if startTime.IsZero() || endTime.IsZero() { - return nil - } - - return &RTPDeltaInfo{ - StartTime: startTime, - Duration: endTime.Sub(startTime), - Packets: packets, - Bytes: bytes, - HeaderBytes: headerBytes, - PacketsDuplicate: packetsDuplicate, - BytesDuplicate: bytesDuplicate, - HeaderBytesDuplicate: headerBytesDuplicate, - PacketsPadding: packetsPadding, - BytesPadding: bytesPadding, - HeaderBytesPadding: headerBytesPadding, - PacketsLost: packetsLost, - PacketsMissing: packetsMissing, - PacketsOutOfOrder: packetsOutOfOrder, - Frames: frames, - RttMax: maxRtt, - JitterMax: maxJitter, - Nacks: nacks, - Plis: plis, - Firs: firs, - } -} - -// ------------------------------------------------------------------- diff --git a/pkg/sfu/buffer/rtpstats_base.go b/pkg/sfu/buffer/rtpstats_base.go new file mode 100644 index 000000000..f02e9241b --- /dev/null +++ b/pkg/sfu/buffer/rtpstats_base.go @@ -0,0 +1,1254 @@ +// Copyright 2023 LiveKit, Inc. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package buffer + +import ( + "fmt" + "sync" + "time" + + "google.golang.org/protobuf/types/known/timestamppb" + + "github.com/livekit/mediatransportutil" + "github.com/livekit/protocol/livekit" + "github.com/livekit/protocol/logger" +) + +const ( + cGapHistogramNumBins = 101 + cNumSequenceNumbers = 65536 + cFirstSnapshotID = 1 + cSnInfoSize = 8192 + cSnInfoMask = cSnInfoSize - 1 + + cFirstPacketTimeAdjustWindow = 2 * time.Minute + cFirstPacketTimeAdjustThreshold = 5 * time.Second +) + +// ------------------------------------------------------- + +func RTPDriftToString(r *livekit.RTPDrift) string { + if r == nil { + return "-" + } + + str := fmt.Sprintf("t: %+v|%+v|%.2fs", r.StartTime.AsTime().Format(time.UnixDate), r.EndTime.AsTime().Format(time.UnixDate), r.Duration) + str += fmt.Sprintf(", ts: %d|%d|%d", r.StartTimestamp, r.EndTimestamp, r.RtpClockTicks) + str += fmt.Sprintf(", d: %d|%.2fms", r.DriftSamples, r.DriftMs) + str += fmt.Sprintf(", cr: %.2f", r.ClockRate) + return str +} + +// ------------------------------------------------------- + +type intervalStats struct { + packets uint64 + bytes uint64 + headerBytes uint64 + packetsPadding uint64 + bytesPadding uint64 + headerBytesPadding uint64 + packetsLost uint64 + packetsOutOfOrder uint64 + frames uint32 +} + +type RTPDeltaInfo struct { + StartTime time.Time + Duration time.Duration + Packets uint32 + Bytes uint64 + HeaderBytes uint64 + PacketsDuplicate uint32 + BytesDuplicate uint64 + HeaderBytesDuplicate uint64 + PacketsPadding uint32 + BytesPadding uint64 + HeaderBytesPadding uint64 + PacketsLost uint32 + PacketsMissing uint32 + PacketsOutOfOrder uint32 + Frames uint32 + RttMax uint32 + JitterMax float64 + Nacks uint32 + Plis uint32 + Firs uint32 +} + +type snapshot struct { + startTime time.Time + extStartSN uint64 + packetsDuplicate uint64 + bytesDuplicate uint64 + headerBytesDuplicate uint64 + packetsLostOverridden uint64 + nacks uint32 + plis uint32 + firs uint32 + maxRtt uint32 + maxJitter float64 +} + +type snInfo struct { + hdrSize uint16 + pktSize uint16 + isPaddingOnly bool + marker bool + isOutOfOrder bool +} + +type RTCPSenderReportData struct { + RTPTimestamp uint32 + RTPTimestampExt uint64 + NTPTimestamp mediatransportutil.NtpTime + PacketCount uint32 + PacketCountExt uint64 + PaddingOnlyDrops uint64 + At time.Time +} + +type RTPStatsParams struct { + ClockRate uint32 + Logger logger.Logger +} + +type rtpStatsBase struct { + params RTPStatsParams + logger logger.Logger + + lock sync.RWMutex + + initialized bool + + startTime time.Time + endTime time.Time + + firstTime time.Time + highestTime time.Time + + lastTransit uint64 + lastJitterExtTimestamp uint64 + + bytes uint64 + headerBytes uint64 + bytesDuplicate uint64 + headerBytesDuplicate uint64 + bytesPadding uint64 + headerBytesPadding uint64 + packetsDuplicate uint64 + packetsPadding uint64 + + packetsOutOfOrder uint64 + + packetsLost uint64 + packetsLostOverridden uint64 + + frames uint32 + + jitter float64 + maxJitter float64 + + snInfos [cSnInfoSize]snInfo + + gapHistogram [cGapHistogramNumBins]uint32 + + nacks uint32 + nackAcks uint32 + nackMisses uint32 + nackRepeated uint32 + + plis uint32 + lastPli time.Time + + layerLockPlis uint32 + lastLayerLockPli time.Time + + firs uint32 + lastFir time.Time + + keyFrames uint32 + lastKeyFrame time.Time + + rtt uint32 + maxRtt uint32 + + srFirst *RTCPSenderReportData + srNewest *RTCPSenderReportData + + nextSnapshotID uint32 + snapshots map[uint32]*snapshot +} + +func newRTPStatsBase(params RTPStatsParams) *rtpStatsBase { + return &rtpStatsBase{ + params: params, + logger: params.Logger, + nextSnapshotID: cFirstSnapshotID, + snapshots: make(map[uint32]*snapshot), + } +} + +func (r *rtpStatsBase) seed(from *rtpStatsBase) bool { + if from == nil || !from.initialized { + return false + } + + r.initialized = from.initialized + + r.startTime = from.startTime + // do not clone endTime as a non-zero endTime indicates an ended object + + r.firstTime = from.firstTime + r.highestTime = from.highestTime + + r.lastTransit = from.lastTransit + r.lastJitterExtTimestamp = from.lastJitterExtTimestamp + + r.bytes = from.bytes + r.headerBytes = from.headerBytes + r.bytesDuplicate = from.bytesDuplicate + r.headerBytesDuplicate = from.headerBytesDuplicate + r.bytesPadding = from.bytesPadding + r.headerBytesPadding = from.headerBytesPadding + r.packetsDuplicate = from.packetsDuplicate + r.packetsPadding = from.packetsPadding + + r.packetsOutOfOrder = from.packetsOutOfOrder + + r.packetsLost = from.packetsLost + + r.frames = from.frames + + r.jitter = from.jitter + r.maxJitter = from.maxJitter + + r.snInfos = from.snInfos + + r.gapHistogram = from.gapHistogram + + r.nacks = from.nacks + r.nackAcks = from.nackAcks + r.nackMisses = from.nackMisses + r.nackRepeated = from.nackRepeated + + r.plis = from.plis + r.lastPli = from.lastPli + + r.layerLockPlis = from.layerLockPlis + r.lastLayerLockPli = from.lastLayerLockPli + + r.firs = from.firs + r.lastFir = from.lastFir + + r.keyFrames = from.keyFrames + r.lastKeyFrame = from.lastKeyFrame + + r.rtt = from.rtt + r.maxRtt = from.maxRtt + + if from.srFirst != nil { + srFirst := *from.srFirst + r.srFirst = &srFirst + } else { + r.srFirst = nil + } + if from.srNewest != nil { + srNewest := *from.srNewest + r.srNewest = &srNewest + } else { + r.srNewest = nil + } + + r.nextSnapshotID = from.nextSnapshotID + for id, ss := range from.snapshots { + ssCopy := *ss + r.snapshots[id] = &ssCopy + } + return true +} + +func (r *rtpStatsBase) SetLogger(logger logger.Logger) { + r.logger = logger +} + +func (r *rtpStatsBase) Stop() { + r.lock.Lock() + defer r.lock.Unlock() + + r.endTime = time.Now() +} + +func (r *rtpStatsBase) newSnapshotID(extStartSN uint64) uint32 { + id := r.nextSnapshotID + r.nextSnapshotID++ + + if r.initialized { + r.snapshots[id] = &snapshot{ + startTime: time.Now(), + extStartSN: extStartSN, + } + } + return id +} + +func (r *rtpStatsBase) IsActive() bool { + r.lock.RLock() + defer r.lock.RUnlock() + + return r.initialized && r.endTime.IsZero() +} + +func (r *rtpStatsBase) UpdateNack(nackCount uint32) { + r.lock.Lock() + defer r.lock.Unlock() + + if !r.endTime.IsZero() { + return + } + + r.nacks += nackCount +} + +func (r *rtpStatsBase) UpdateNackProcessed(nackAckCount uint32, nackMissCount uint32, nackRepeatedCount uint32) { + r.lock.Lock() + defer r.lock.Unlock() + + if !r.endTime.IsZero() { + return + } + + r.nackAcks += nackAckCount + r.nackMisses += nackMissCount + r.nackRepeated += nackRepeatedCount +} + +func (r *rtpStatsBase) UpdatePliAndTime(pliCount uint32) { + r.lock.Lock() + defer r.lock.Unlock() + + if !r.endTime.IsZero() { + return + } + + r.updatePliLocked(pliCount) + r.updatePliTimeLocked() +} + +func (r *rtpStatsBase) UpdatePli(pliCount uint32) { + r.lock.Lock() + defer r.lock.Unlock() + + if !r.endTime.IsZero() { + return + } + + r.updatePliLocked(pliCount) +} + +func (r *rtpStatsBase) updatePliLocked(pliCount uint32) { + r.plis += pliCount +} + +func (r *rtpStatsBase) UpdatePliTime() { + r.lock.Lock() + defer r.lock.Unlock() + + if !r.endTime.IsZero() { + return + } + + r.updatePliTimeLocked() +} + +func (r *rtpStatsBase) updatePliTimeLocked() { + r.lastPli = time.Now() +} + +func (r *rtpStatsBase) LastPli() time.Time { + r.lock.RLock() + defer r.lock.RUnlock() + + return r.lastPli +} + +func (r *rtpStatsBase) TimeSinceLastPli() int64 { + r.lock.RLock() + defer r.lock.RUnlock() + + return time.Now().UnixNano() - r.lastPli.UnixNano() +} + +func (r *rtpStatsBase) UpdateLayerLockPliAndTime(pliCount uint32) { + r.lock.Lock() + defer r.lock.Unlock() + + if !r.endTime.IsZero() { + return + } + + r.layerLockPlis += pliCount + r.lastLayerLockPli = time.Now() +} + +func (r *rtpStatsBase) UpdateFir(firCount uint32) { + r.lock.Lock() + defer r.lock.Unlock() + + if !r.endTime.IsZero() { + return + } + + r.firs += firCount +} + +func (r *rtpStatsBase) UpdateFirTime() { + r.lock.Lock() + defer r.lock.Unlock() + + if !r.endTime.IsZero() { + return + } + + r.lastFir = time.Now() +} + +func (r *rtpStatsBase) UpdateKeyFrame(kfCount uint32) { + r.lock.Lock() + defer r.lock.Unlock() + + if !r.endTime.IsZero() { + return + } + + r.keyFrames += kfCount + r.lastKeyFrame = time.Now() +} + +func (r *rtpStatsBase) UpdateRtt(rtt uint32) { + r.lock.Lock() + defer r.lock.Unlock() + + if !r.endTime.IsZero() { + return + } + + r.rtt = rtt + if rtt > r.maxRtt { + r.maxRtt = rtt + } + + for _, s := range r.snapshots { + if rtt > s.maxRtt { + s.maxRtt = rtt + } + } +} + +func (r *rtpStatsBase) GetRtt() uint32 { + r.lock.RLock() + defer r.lock.RUnlock() + + return r.rtt +} + +func (r *rtpStatsBase) maybeAdjustFirstPacketTime(ets uint64, extStartTS uint64) { + if time.Since(r.startTime) > cFirstPacketTimeAdjustWindow { + return + } + + // for some time after the start, adjust time of first packet. + // Helps improve accuracy of expected timestamp calculation. + // Adjusting only one way, i. e. if the first sample experienced + // 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. + samplesDiff := int64(ets - extStartTS) + if samplesDiff < 0 { + // out-of-order, skip + return + } + + samplesDuration := time.Duration(float64(samplesDiff) / float64(r.params.ClockRate) * float64(time.Second)) + now := time.Now() + firstTime := now.Add(-samplesDuration) + if firstTime.Before(r.firstTime) { + r.logger.Debugw( + "adjusting first packet time", + "startTime", r.startTime.String(), + "nowTime", now.String(), + "before", r.firstTime.String(), + "after", firstTime.String(), + "adjustment", r.firstTime.Sub(firstTime), + "extNowTS", ets, + "extStartTS", extStartTS, + ) + if r.firstTime.Sub(firstTime) > cFirstPacketTimeAdjustThreshold { + r.logger.Infow("first packet time adjustment too big, ignoring", + "startTime", r.startTime.String(), + "nowTime", now.String(), + "before", r.firstTime.String(), + "after", firstTime.String(), + "adjustment", r.firstTime.Sub(firstTime), + "extNowTS", ets, + "extStartTS", extStartTS, + ) + } else { + r.firstTime = firstTime + } + } +} + +func (r *rtpStatsBase) getTotalPacketsPrimary(extStartSN, extHighestSN uint64) uint64 { + packetsExpected := extHighestSN - extStartSN + 1 + if r.packetsLost > packetsExpected { + // should not happen + return 0 + } + + packetsSeen := packetsExpected - r.packetsLost + if r.packetsPadding > packetsSeen { + return 0 + } + + return packetsSeen - r.packetsPadding +} + +func (r *rtpStatsBase) deltaInfo(snapshotID uint32, extStartSN uint64, extHighestSN uint64) *RTPDeltaInfo { + then, now := r.getAndResetSnapshot(snapshotID, extStartSN, extHighestSN) + + if now == nil || then == nil { + return nil + } + + startTime := then.startTime + endTime := now.startTime + + packetsExpected := now.extStartSN - then.extStartSN + if packetsExpected > cNumSequenceNumbers { + r.logger.Errorw( + "too many packets expected in delta", + fmt.Errorf("start: %d, end: %d, expected: %d", then.extStartSN, now.extStartSN, packetsExpected), + ) + return nil + } + if packetsExpected == 0 { + return &RTPDeltaInfo{ + StartTime: startTime, + Duration: endTime.Sub(startTime), + } + } + + intervalStats := r.getIntervalStats(then.extStartSN, now.extStartSN, extHighestSN) + return &RTPDeltaInfo{ + StartTime: startTime, + Duration: endTime.Sub(startTime), + Packets: uint32(packetsExpected - intervalStats.packetsPadding), + Bytes: intervalStats.bytes, + HeaderBytes: intervalStats.headerBytes, + PacketsDuplicate: uint32(now.packetsDuplicate - then.packetsDuplicate), + BytesDuplicate: now.bytesDuplicate - then.bytesDuplicate, + HeaderBytesDuplicate: now.headerBytesDuplicate - then.headerBytesDuplicate, + PacketsPadding: uint32(intervalStats.packetsPadding), + BytesPadding: intervalStats.bytesPadding, + HeaderBytesPadding: intervalStats.headerBytesPadding, + PacketsLost: uint32(intervalStats.packetsLost), + Frames: intervalStats.frames, + RttMax: then.maxRtt, + JitterMax: then.maxJitter / float64(r.params.ClockRate) * 1e6, + Nacks: now.nacks - then.nacks, + Plis: now.plis - then.plis, + Firs: now.firs - then.firs, + } +} + +func (r *rtpStatsBase) toString( + extStartSN, extHighestSN, extStartTS, extHighestTS uint64, + packetsLost uint64, + jitter, maxJitter float64, +) string { + p := r.toProto( + extStartSN, extHighestSN, extStartTS, extHighestTS, + packetsLost, + jitter, maxJitter, + ) + if p == nil { + return "" + } + + expectedPackets := extHighestSN - extStartSN + 1 + expectedPacketRate := float64(expectedPackets) / p.Duration + + str := fmt.Sprintf("t: %+v|%+v|%.2fs", p.StartTime.AsTime().Format(time.UnixDate), p.EndTime.AsTime().Format(time.UnixDate), p.Duration) + + str += fmt.Sprintf(", sn: %d|%d", extStartSN, extHighestSN) + str += fmt.Sprintf(", ep: %d|%.2f/s", expectedPackets, expectedPacketRate) + + str += fmt.Sprintf(", p: %d|%.2f/s", p.Packets, p.PacketRate) + str += fmt.Sprintf(", l: %d|%.1f/s|%.2f%%", p.PacketsLost, p.PacketLossRate, p.PacketLossPercentage) + str += fmt.Sprintf(", b: %d|%.1fbps|%d", p.Bytes, p.Bitrate, p.HeaderBytes) + str += fmt.Sprintf(", f: %d|%.1f/s / %d|%+v", p.Frames, p.FrameRate, p.KeyFrames, p.LastKeyFrame.AsTime().Format(time.UnixDate)) + + str += fmt.Sprintf(", d: %d|%.2f/s", p.PacketsDuplicate, p.PacketDuplicateRate) + str += fmt.Sprintf(", bd: %d|%.1fbps|%d", p.BytesDuplicate, p.BitrateDuplicate, p.HeaderBytesDuplicate) + + str += fmt.Sprintf(", pp: %d|%.2f/s", p.PacketsPadding, p.PacketPaddingRate) + str += fmt.Sprintf(", bp: %d|%.1fbps|%d", p.BytesPadding, p.BitratePadding, p.HeaderBytesPadding) + + str += fmt.Sprintf(", o: %d", p.PacketsOutOfOrder) + + str += fmt.Sprintf(", c: %d, j: %d(%.1fus)|%d(%.1fus)", r.params.ClockRate, uint32(jitter), p.JitterCurrent, uint32(maxJitter), p.JitterMax) + + if len(p.GapHistogram) != 0 { + first := true + str += ", gh:[" + for burst, count := range p.GapHistogram { + if !first { + str += ", " + } + first = false + str += fmt.Sprintf("%d:%d", burst, count) + } + str += "]" + } + + str += ", n:" + str += fmt.Sprintf("%d|%d|%d|%d", p.Nacks, p.NackAcks, p.NackMisses, p.NackRepeated) + + str += ", pli:" + str += fmt.Sprintf("%d|%+v / %d|%+v", + p.Plis, p.LastPli.AsTime().Format(time.UnixDate), + p.LayerLockPlis, p.LastLayerLockPli.AsTime().Format(time.UnixDate), + ) + + str += ", fir:" + str += fmt.Sprintf("%d|%+v", p.Firs, p.LastFir.AsTime().Format(time.UnixDate)) + + str += ", rtt(ms):" + str += fmt.Sprintf("%d|%d", p.RttCurrent, p.RttMax) + + str += fmt.Sprintf(", pd: %s, rd: %s", RTPDriftToString(p.PacketDrift), RTPDriftToString(p.ReportDrift)) + return str +} + +func (r *rtpStatsBase) toProto( + extStartSN, extHighestSN, extStartTS, extHighestTS uint64, + packetsLost uint64, + jitter, maxJitter float64, +) *livekit.RTPStats { + if r.startTime.IsZero() { + return nil + } + + endTime := r.endTime + if endTime.IsZero() { + endTime = time.Now() + } + elapsed := endTime.Sub(r.startTime).Seconds() + if elapsed == 0.0 { + return nil + } + + packets := r.getTotalPacketsPrimary(extStartSN, extHighestSN) + packetRate := float64(packets) / elapsed + bitrate := float64(r.bytes) * 8.0 / elapsed + + frameRate := float64(r.frames) / elapsed + + packetsExpected := extHighestSN - extStartSN + 1 + packetLostRate := float64(packetsLost) / elapsed + packetLostPercentage := float32(packetsLost) / float32(packetsExpected) * 100.0 + + packetDuplicateRate := float64(r.packetsDuplicate) / elapsed + bitrateDuplicate := float64(r.bytesDuplicate) * 8.0 / elapsed + + packetPaddingRate := float64(r.packetsPadding) / elapsed + bitratePadding := float64(r.bytesPadding) * 8.0 / elapsed + + jitterTime := jitter / float64(r.params.ClockRate) * 1e6 + maxJitterTime := maxJitter / float64(r.params.ClockRate) * 1e6 + + packetDrift, reportDrift := r.getDrift(extStartTS, extHighestTS) + + p := &livekit.RTPStats{ + StartTime: timestamppb.New(r.startTime), + EndTime: timestamppb.New(endTime), + Duration: elapsed, + Packets: uint32(packets), + PacketRate: packetRate, + Bytes: r.bytes, + HeaderBytes: r.headerBytes, + Bitrate: bitrate, + PacketsLost: uint32(packetsLost), + PacketLossRate: packetLostRate, + PacketLossPercentage: packetLostPercentage, + PacketsDuplicate: uint32(r.packetsDuplicate), + PacketDuplicateRate: packetDuplicateRate, + BytesDuplicate: r.bytesDuplicate, + HeaderBytesDuplicate: r.headerBytesDuplicate, + BitrateDuplicate: bitrateDuplicate, + PacketsPadding: uint32(r.packetsPadding), + PacketPaddingRate: packetPaddingRate, + BytesPadding: r.bytesPadding, + HeaderBytesPadding: r.headerBytesPadding, + BitratePadding: bitratePadding, + PacketsOutOfOrder: uint32(r.packetsOutOfOrder), + Frames: r.frames, + FrameRate: frameRate, + KeyFrames: r.keyFrames, + LastKeyFrame: timestamppb.New(r.lastKeyFrame), + JitterCurrent: jitterTime, + JitterMax: maxJitterTime, + Nacks: r.nacks, + NackAcks: r.nackAcks, + NackMisses: r.nackMisses, + NackRepeated: r.nackRepeated, + Plis: r.plis, + LastPli: timestamppb.New(r.lastPli), + LayerLockPlis: r.layerLockPlis, + LastLayerLockPli: timestamppb.New(r.lastLayerLockPli), + Firs: r.firs, + LastFir: timestamppb.New(r.lastFir), + RttCurrent: r.rtt, + RttMax: r.maxRtt, + PacketDrift: packetDrift, + ReportDrift: reportDrift, + } + + gapsPresent := false + for i := 0; i < len(r.gapHistogram); i++ { + if r.gapHistogram[i] == 0 { + continue + } + + gapsPresent = true + break + } + + if gapsPresent { + p.GapHistogram = make(map[int32]uint32, cGapHistogramNumBins) + for i := 0; i < len(r.gapHistogram); i++ { + if r.gapHistogram[i] == 0 { + continue + } + + p.GapHistogram[int32(i+1)] = r.gapHistogram[i] + } + } + + return p +} + +func (r *rtpStatsBase) getSnInfoOutOfOrderSlot(esn uint64, ehsn uint64) int { + offset := int64(ehsn - esn) + if offset >= cSnInfoSize || offset < 0 { + // too old OR too new (i. e. ahead of highest) + return -1 + } + + return int(esn & cSnInfoMask) +} + +func (r *rtpStatsBase) setSnInfo(esn uint64, ehsn uint64, pktSize uint16, hdrSize uint16, payloadSize uint16, marker bool, isOutOfOrder bool) { + var slot int + if int64(esn-ehsn) < 0 { + slot = r.getSnInfoOutOfOrderSlot(esn, ehsn) + if slot < 0 { + return + } + } else { + slot = int(esn & cSnInfoMask) + } + + snInfo := &r.snInfos[slot] + snInfo.pktSize = pktSize + snInfo.hdrSize = hdrSize + snInfo.isPaddingOnly = payloadSize == 0 + snInfo.marker = marker + snInfo.isOutOfOrder = isOutOfOrder +} + +func (r *rtpStatsBase) clearSnInfos(extStartInclusive uint64, extEndExclusive uint64) { + if extEndExclusive <= extStartInclusive { + return + } + + for esn := extStartInclusive; esn != extEndExclusive; esn++ { + snInfo := &r.snInfos[esn&cSnInfoMask] + snInfo.pktSize = 0 + snInfo.hdrSize = 0 + snInfo.isPaddingOnly = false + snInfo.marker = false + } +} + +func (r *rtpStatsBase) isSnInfoLost(esn uint64, ehsn uint64) bool { + slot := r.getSnInfoOutOfOrderSlot(esn, ehsn) + if slot < 0 { + return false + } + + return r.snInfos[slot].pktSize == 0 +} + +func (r *rtpStatsBase) getIntervalStats(extStartInclusive uint64, extEndExclusive uint64, ehsn uint64) (intervalStats intervalStats) { + packetsNotFound := uint32(0) + processESN := func(esn uint64, ehsn uint64) { + slot := r.getSnInfoOutOfOrderSlot(esn, ehsn) + if slot < 0 { + packetsNotFound++ + return + } + + snInfo := &r.snInfos[slot] + switch { + case snInfo.pktSize == 0: + intervalStats.packetsLost++ + + case snInfo.isPaddingOnly: + intervalStats.packetsPadding++ + intervalStats.bytesPadding += uint64(snInfo.pktSize) + intervalStats.headerBytesPadding += uint64(snInfo.hdrSize) + + default: + intervalStats.packets++ + intervalStats.bytes += uint64(snInfo.pktSize) + intervalStats.headerBytes += uint64(snInfo.hdrSize) + if snInfo.isOutOfOrder { + intervalStats.packetsOutOfOrder++ + } + } + + if snInfo.marker { + intervalStats.frames++ + } + } + + for esn := extStartInclusive; esn != extEndExclusive; esn++ { + processESN(esn, ehsn) + } + + if packetsNotFound != 0 { + r.logger.Errorw( + "could not find some packets", nil, + "start", extStartInclusive, + "end", extEndExclusive, + "count", packetsNotFound, + "highestSN", ehsn, + ) + } + return +} + +func (r *rtpStatsBase) updateJitter(ets uint64, packetTime time.Time) float64 { + // Do not update jitter on multiple packets of same frame. + // All packets of a frame have the same time stamp. + // NOTE: This does not protect against using more than one packet of the same frame + // if packets arrive out-of-order. For example, + // p1f1 -> p1f2 -> p2f1 + // In this case, p2f1 (packet 2, frame 1) will still be used in jitter calculation + // although it is the second packet of a frame because of out-of-order receival. + if r.lastJitterExtTimestamp != ets { + timeSinceFirst := packetTime.Sub(r.firstTime) + packetTimeRTP := uint64(timeSinceFirst.Nanoseconds() * int64(r.params.ClockRate) / 1e9) + transit := packetTimeRTP - ets + + if r.lastTransit != 0 { + d := int64(transit - r.lastTransit) + if d < 0 { + d = -d + } + r.jitter += (float64(d) - r.jitter) / 16 + if r.jitter > r.maxJitter { + r.maxJitter = r.jitter + } + + for _, s := range r.snapshots { + if r.jitter > s.maxJitter { + s.maxJitter = r.jitter + } + } + } + + r.lastTransit = transit + r.lastJitterExtTimestamp = ets + } + return r.jitter +} + +func (r *rtpStatsBase) getAndResetSnapshot(snapshotID uint32, extStartSN uint64, extHighestSN uint64) (*snapshot, *snapshot) { + if !r.initialized { + return nil, nil + } + + then := r.snapshots[snapshotID] + if then == nil { + then = &snapshot{ + startTime: r.startTime, + extStartSN: extStartSN, + } + r.snapshots[snapshotID] = then + } + + // snapshot now + r.snapshots[snapshotID] = &snapshot{ + startTime: time.Now(), + extStartSN: extHighestSN + 1, + packetsDuplicate: r.packetsDuplicate, + bytesDuplicate: r.bytesDuplicate, + headerBytesDuplicate: r.headerBytesDuplicate, + nacks: r.nacks, + plis: r.plis, + firs: r.firs, + maxJitter: r.jitter, + maxRtt: r.rtt, + } + // make a copy so that it can be used independently + now := *r.snapshots[snapshotID] + + return then, &now +} + +func (r *rtpStatsBase) getDrift(extStartTS, extHighestTS uint64) (packetDrift *livekit.RTPDrift, reportDrift *livekit.RTPDrift) { + if !r.firstTime.IsZero() { + elapsed := r.highestTime.Sub(r.firstTime) + rtpClockTicks := extHighestTS - extStartTS + driftSamples := int64(rtpClockTicks - uint64(elapsed.Nanoseconds()*int64(r.params.ClockRate)/1e9)) + if elapsed.Seconds() > 0.0 { + packetDrift = &livekit.RTPDrift{ + StartTime: timestamppb.New(r.firstTime), + EndTime: timestamppb.New(r.highestTime), + Duration: elapsed.Seconds(), + StartTimestamp: extStartTS, + EndTimestamp: extHighestTS, + RtpClockTicks: rtpClockTicks, + DriftSamples: driftSamples, + DriftMs: (float64(driftSamples) * 1000) / float64(r.params.ClockRate), + ClockRate: float64(rtpClockTicks) / elapsed.Seconds(), + } + } + } + + if r.srFirst != nil && r.srNewest != nil && r.srFirst.RTPTimestamp != r.srNewest.RTPTimestamp { + elapsed := r.srNewest.NTPTimestamp.Time().Sub(r.srFirst.NTPTimestamp.Time()) + rtpClockTicks := r.srNewest.RTPTimestampExt - r.srFirst.RTPTimestampExt + driftSamples := int64(rtpClockTicks - uint64(elapsed.Nanoseconds()*int64(r.params.ClockRate)/1e9)) + if elapsed.Seconds() > 0.0 { + reportDrift = &livekit.RTPDrift{ + StartTime: timestamppb.New(r.srFirst.NTPTimestamp.Time()), + EndTime: timestamppb.New(r.srNewest.NTPTimestamp.Time()), + Duration: elapsed.Seconds(), + StartTimestamp: r.srFirst.RTPTimestampExt, + EndTimestamp: r.srNewest.RTPTimestampExt, + RtpClockTicks: rtpClockTicks, + DriftSamples: driftSamples, + DriftMs: (float64(driftSamples) * 1000) / float64(r.params.ClockRate), + ClockRate: float64(rtpClockTicks) / elapsed.Seconds(), + } + } + } + return +} + +func (r *rtpStatsBase) updateGapHistogram(gap int) { + if gap < 2 { + return + } + + missing := gap - 1 + if missing > len(r.gapHistogram) { + r.gapHistogram[len(r.gapHistogram)-1]++ + } else { + r.gapHistogram[missing-1]++ + } +} + +// ---------------------------------- + +func AggregateRTPStats(statsList []*livekit.RTPStats) *livekit.RTPStats { + if len(statsList) == 0 { + return nil + } + + startTime := time.Time{} + endTime := time.Time{} + + packets := uint32(0) + bytes := uint64(0) + headerBytes := uint64(0) + packetsLost := uint32(0) + packetsDuplicate := uint32(0) + bytesDuplicate := uint64(0) + headerBytesDuplicate := uint64(0) + packetsPadding := uint32(0) + bytesPadding := uint64(0) + headerBytesPadding := uint64(0) + packetsOutOfOrder := uint32(0) + frames := uint32(0) + keyFrames := uint32(0) + lastKeyFrame := time.Time{} + jitter := 0.0 + maxJitter := float64(0) + gapHistogram := make(map[int32]uint32, cGapHistogramNumBins) + nacks := uint32(0) + nackAcks := uint32(0) + nackMisses := uint32(0) + nackRepeated := uint32(0) + plis := uint32(0) + lastPli := time.Time{} + layerLockPlis := uint32(0) + lastLayerLockPli := time.Time{} + firs := uint32(0) + lastFir := time.Time{} + rtt := uint32(0) + maxRtt := uint32(0) + + for _, stats := range statsList { + if startTime.IsZero() || startTime.After(stats.StartTime.AsTime()) { + startTime = stats.StartTime.AsTime() + } + + if endTime.IsZero() || endTime.Before(stats.EndTime.AsTime()) { + endTime = stats.EndTime.AsTime() + } + + packets += stats.Packets + bytes += stats.Bytes + headerBytes += stats.HeaderBytes + + packetsLost += stats.PacketsLost + + packetsDuplicate += stats.PacketsDuplicate + bytesDuplicate += stats.BytesDuplicate + headerBytesDuplicate += stats.HeaderBytesDuplicate + + packetsPadding += stats.PacketsPadding + bytesPadding += stats.BytesPadding + headerBytesPadding += stats.HeaderBytesPadding + + packetsOutOfOrder += stats.PacketsOutOfOrder + + frames += stats.Frames + + keyFrames += stats.KeyFrames + if lastKeyFrame.IsZero() || lastKeyFrame.Before(stats.LastKeyFrame.AsTime()) { + lastKeyFrame = stats.LastKeyFrame.AsTime() + } + + jitter += stats.JitterCurrent + if stats.JitterMax > maxJitter { + maxJitter = stats.JitterMax + } + + for burst, count := range stats.GapHistogram { + gapHistogram[burst] += count + } + + nacks += stats.Nacks + nackAcks += stats.NackAcks + nackMisses += stats.NackMisses + nackRepeated += stats.NackRepeated + + plis += stats.Plis + if lastPli.IsZero() || lastPli.Before(stats.LastPli.AsTime()) { + lastPli = stats.LastPli.AsTime() + } + + layerLockPlis += stats.LayerLockPlis + if lastLayerLockPli.IsZero() || lastLayerLockPli.Before(stats.LastLayerLockPli.AsTime()) { + lastLayerLockPli = stats.LastLayerLockPli.AsTime() + } + + firs += stats.Firs + if lastFir.IsZero() || lastPli.Before(stats.LastFir.AsTime()) { + lastFir = stats.LastFir.AsTime() + } + + rtt += stats.RttCurrent + if stats.RttMax > maxRtt { + maxRtt = stats.RttMax + } + } + + if endTime.IsZero() { + endTime = time.Now() + } + elapsed := endTime.Sub(startTime).Seconds() + + packetLostRate := float64(packetsLost) / elapsed + packetLostPercentage := float32(packetsLost) / (float32(packets) + float32(packetsLost)) * 100.0 + + packetRate := float64(packets) / elapsed + packetDuplicateRate := float64(packetsDuplicate) / elapsed + packetPaddingRate := float64(packetsPadding) / elapsed + + bitrate := float64(bytes) * 8.0 / elapsed + bitrateDuplicate := float64(bytesDuplicate) * 8.0 / elapsed + bitratePadding := float64(bytesPadding) * 8.0 / elapsed + + frameRate := float64(frames) / elapsed + + return &livekit.RTPStats{ + StartTime: timestamppb.New(startTime), + EndTime: timestamppb.New(endTime), + Duration: elapsed, + Packets: packets, + PacketRate: packetRate, + Bytes: bytes, + HeaderBytes: headerBytes, + Bitrate: bitrate, + PacketsLost: packetsLost, + PacketLossRate: packetLostRate, + PacketLossPercentage: packetLostPercentage, + PacketsDuplicate: packetsDuplicate, + PacketDuplicateRate: packetDuplicateRate, + BytesDuplicate: bytesDuplicate, + HeaderBytesDuplicate: headerBytesDuplicate, + BitrateDuplicate: bitrateDuplicate, + PacketsPadding: packetsPadding, + PacketPaddingRate: packetPaddingRate, + BytesPadding: bytesPadding, + HeaderBytesPadding: headerBytesPadding, + BitratePadding: bitratePadding, + PacketsOutOfOrder: packetsOutOfOrder, + Frames: frames, + FrameRate: frameRate, + KeyFrames: keyFrames, + LastKeyFrame: timestamppb.New(lastKeyFrame), + JitterCurrent: jitter / float64(len(statsList)), + JitterMax: maxJitter, + GapHistogram: gapHistogram, + Nacks: nacks, + NackAcks: nackAcks, + NackMisses: nackMisses, + NackRepeated: nackRepeated, + Plis: plis, + LastPli: timestamppb.New(lastPli), + LayerLockPlis: layerLockPlis, + LastLayerLockPli: timestamppb.New(lastLayerLockPli), + Firs: firs, + LastFir: timestamppb.New(lastFir), + RttCurrent: rtt / uint32(len(statsList)), + RttMax: maxRtt, + // no aggregation for drift calculations + } +} + +func AggregateRTPDeltaInfo(deltaInfoList []*RTPDeltaInfo) *RTPDeltaInfo { + if len(deltaInfoList) == 0 { + return nil + } + + startTime := time.Time{} + endTime := time.Time{} + + packets := uint32(0) + bytes := uint64(0) + headerBytes := uint64(0) + + packetsDuplicate := uint32(0) + bytesDuplicate := uint64(0) + headerBytesDuplicate := uint64(0) + + packetsPadding := uint32(0) + bytesPadding := uint64(0) + headerBytesPadding := uint64(0) + + packetsLost := uint32(0) + packetsMissing := uint32(0) + packetsOutOfOrder := uint32(0) + + frames := uint32(0) + + maxRtt := uint32(0) + maxJitter := float64(0) + + nacks := uint32(0) + plis := uint32(0) + firs := uint32(0) + + for _, deltaInfo := range deltaInfoList { + if deltaInfo == nil { + continue + } + + if startTime.IsZero() || startTime.After(deltaInfo.StartTime) { + startTime = deltaInfo.StartTime + } + + endedAt := deltaInfo.StartTime.Add(deltaInfo.Duration) + if endTime.IsZero() || endTime.Before(endedAt) { + endTime = endedAt + } + + packets += deltaInfo.Packets + bytes += deltaInfo.Bytes + headerBytes += deltaInfo.HeaderBytes + + packetsDuplicate += deltaInfo.PacketsDuplicate + bytesDuplicate += deltaInfo.BytesDuplicate + headerBytesDuplicate += deltaInfo.HeaderBytesDuplicate + + packetsPadding += deltaInfo.PacketsPadding + bytesPadding += deltaInfo.BytesPadding + headerBytesPadding += deltaInfo.HeaderBytesPadding + + packetsLost += deltaInfo.PacketsLost + packetsMissing += deltaInfo.PacketsMissing + packetsOutOfOrder += deltaInfo.PacketsOutOfOrder + + frames += deltaInfo.Frames + + if deltaInfo.RttMax > maxRtt { + maxRtt = deltaInfo.RttMax + } + + if deltaInfo.JitterMax > maxJitter { + maxJitter = deltaInfo.JitterMax + } + + nacks += deltaInfo.Nacks + plis += deltaInfo.Plis + firs += deltaInfo.Firs + } + if startTime.IsZero() || endTime.IsZero() { + return nil + } + + return &RTPDeltaInfo{ + StartTime: startTime, + Duration: endTime.Sub(startTime), + Packets: packets, + Bytes: bytes, + HeaderBytes: headerBytes, + PacketsDuplicate: packetsDuplicate, + BytesDuplicate: bytesDuplicate, + HeaderBytesDuplicate: headerBytesDuplicate, + PacketsPadding: packetsPadding, + BytesPadding: bytesPadding, + HeaderBytesPadding: headerBytesPadding, + PacketsLost: packetsLost, + PacketsMissing: packetsMissing, + PacketsOutOfOrder: packetsOutOfOrder, + Frames: frames, + RttMax: maxRtt, + JitterMax: maxJitter, + Nacks: nacks, + Plis: plis, + Firs: firs, + } +} + +// ------------------------------------------------------------------- diff --git a/pkg/sfu/buffer/rtpstats_receiver.go b/pkg/sfu/buffer/rtpstats_receiver.go new file mode 100644 index 000000000..eeb8e5ef5 --- /dev/null +++ b/pkg/sfu/buffer/rtpstats_receiver.go @@ -0,0 +1,471 @@ +// Copyright 2023 LiveKit, Inc. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package buffer + +import ( + "fmt" + "time" + + "github.com/pion/rtcp" + + "github.com/livekit/livekit-server/pkg/sfu/utils" + "github.com/livekit/protocol/livekit" +) + +type RTPFlowState struct { + IsNotHandled bool + + HasLoss bool + LossStartInclusive uint64 + LossEndExclusive uint64 + + IsDuplicate bool + IsOutOfOrder bool + + ExtSequenceNumber uint64 + ExtTimestamp uint64 +} + +type RTPStatsReceiver struct { + *rtpStatsBase + + resyncOnNextPacket bool + shouldDiscountPaddingOnlyDrops bool + + sequenceNumber *utils.WrapAround[uint16, uint64] + + timestamp *utils.WrapAround[uint32, uint64] +} + +func NewRTPStatsReceiver(params RTPStatsParams) *RTPStatsReceiver { + return &RTPStatsReceiver{ + rtpStatsBase: newRTPStatsBase(params), + sequenceNumber: utils.NewWrapAround[uint16, uint64](), + timestamp: utils.NewWrapAround[uint32, uint64](), + } +} + +func (r *RTPStatsReceiver) NewSnapshotId() uint32 { + r.lock.Lock() + defer r.lock.Unlock() + + return r.newSnapshotID(r.sequenceNumber.GetExtendedStart()) +} + +func (r *RTPStatsReceiver) Update( + packetTime time.Time, + sequenceNumber uint16, + timestamp uint32, + marker bool, + hdrSize int, + payloadSize int, + paddingSize int, +) (flowState RTPFlowState) { + r.lock.Lock() + defer r.lock.Unlock() + + if !r.endTime.IsZero() { + flowState.IsNotHandled = true + return + } + + if r.resyncOnNextPacket { + r.resyncOnNextPacket = false + r.resync(packetTime, sequenceNumber, timestamp) + } + + var resSN utils.WrapAroundUpdateResult[uint64] + var resTS utils.WrapAroundUpdateResult[uint64] + if !r.initialized { + if payloadSize == 0 { + // do not start on a padding only packet + flowState.IsNotHandled = true + return + } + + r.initialized = true + + r.startTime = time.Now() + + r.firstTime = packetTime + r.highestTime = packetTime + + resSN = r.sequenceNumber.Update(sequenceNumber) + resTS = r.timestamp.Update(timestamp) + + // initialize snapshots if any + for i := uint32(cFirstSnapshotID); i < r.nextSnapshotID; i++ { + r.snapshots[i] = &snapshot{ + startTime: r.startTime, + extStartSN: r.sequenceNumber.GetExtendedStart(), + } + } + + r.logger.Debugw( + "rtp receiver stream start", + "startTime", r.startTime.String(), + "firstTime", r.firstTime.String(), + "startSN", r.sequenceNumber.GetExtendedStart(), + "startTS", r.timestamp.GetExtendedStart(), + ) + } else { + resSN = r.sequenceNumber.Update(sequenceNumber) + resTS = r.timestamp.Update(timestamp) + } + + pktSize := uint64(hdrSize + payloadSize + paddingSize) + gapSN := int64(resSN.ExtendedVal - resSN.PreExtendedHighest) + if gapSN <= 0 { // duplicate OR out-of-order + if payloadSize == 0 { + // do not start on a padding only packet + if resTS.IsRestart { + r.logger.Infow("rolling back timestamp restart", "tsBefore", r.timestamp.GetExtendedStart(), "tsAfter", resTS.PreExtendedStart) + r.timestamp.RollbackRestart(resTS.PreExtendedStart) + } + if resSN.IsRestart { + r.logger.Infow("rolling back sequence number restart", "snBefore", r.sequenceNumber.GetExtendedStart(), "snAfter", resSN.PreExtendedStart) + r.sequenceNumber.RollbackRestart(resSN.PreExtendedStart) + return + } + } + + if gapSN != 0 { + r.packetsOutOfOrder++ + } + + if resSN.IsRestart { + r.packetsLost += resSN.PreExtendedStart - resSN.ExtendedVal + + extStartSN := r.sequenceNumber.GetExtendedStart() + for _, s := range r.snapshots { + if s.extStartSN == resSN.PreExtendedStart { + s.extStartSN = extStartSN + } + } + + r.logger.Infow( + "adjusting start sequence number", + "snBefore", resSN.PreExtendedStart, + "snAfter", resSN.ExtendedVal, + ) + } + + if resTS.IsRestart { + r.logger.Infow( + "adjusting start timestamp", + "tsBefore", resTS.PreExtendedStart, + "tsAfter", resTS.ExtendedVal, + ) + } + + if !r.isSnInfoLost(resSN.ExtendedVal, resSN.PreExtendedHighest) { + r.bytesDuplicate += pktSize + r.headerBytesDuplicate += uint64(hdrSize) + r.packetsDuplicate++ + flowState.IsDuplicate = true + } else { + r.packetsLost-- + r.setSnInfo(resSN.ExtendedVal, resSN.PreExtendedHighest, uint16(pktSize), uint16(hdrSize), uint16(payloadSize), marker, true) + } + + flowState.IsOutOfOrder = true + flowState.ExtSequenceNumber = resSN.ExtendedVal + flowState.ExtTimestamp = resTS.ExtendedVal + } else { // in-order + // update gap histogram + r.updateGapHistogram(int(gapSN)) + + // update missing sequence numbers + r.clearSnInfos(resSN.PreExtendedHighest+1, resSN.ExtendedVal) + r.packetsLost += uint64(gapSN - 1) + + r.setSnInfo(resSN.ExtendedVal, resSN.PreExtendedHighest, uint16(pktSize), uint16(hdrSize), uint16(payloadSize), marker, false) + + if timestamp != uint32(resTS.PreExtendedHighest) { + // update only on first packet as same timestamp could be in multiple packets. + // NOTE: this may not be the first packet with this time stamp if there is packet loss. + r.highestTime = packetTime + } + + if gapSN > 1 { + flowState.HasLoss = true + flowState.LossStartInclusive = resSN.PreExtendedHighest + 1 + flowState.LossEndExclusive = resSN.ExtendedVal + } + flowState.ExtSequenceNumber = resSN.ExtendedVal + flowState.ExtTimestamp = resTS.ExtendedVal + } + + if !flowState.IsDuplicate { + if payloadSize == 0 { + r.packetsPadding++ + r.bytesPadding += pktSize + r.headerBytesPadding += uint64(hdrSize) + } else { + r.bytes += pktSize + r.headerBytes += uint64(hdrSize) + + if marker { + r.frames++ + } + + r.updateJitter(resTS.ExtendedVal, packetTime) + } + } + return +} + +func (r *RTPStatsReceiver) ResyncOnNextPacket(shouldDiscountPaddingOnlyDrops bool) { + r.lock.Lock() + defer r.lock.Unlock() + + r.resyncOnNextPacket = true + r.shouldDiscountPaddingOnlyDrops = shouldDiscountPaddingOnlyDrops +} + +func (r *RTPStatsReceiver) resync(packetTime time.Time, sn uint16, ts uint32) { + if !r.initialized { + return + } + + extHighestSN := r.sequenceNumber.GetExtendedHighest() + var newestPacketCount uint64 + var paddingOnlyDrops uint64 + var extExpectedHighestSN uint64 + var expectedHighestSN uint16 + var snCycles uint64 + + extHighestTS := r.timestamp.GetExtendedHighest() + var newestTS uint64 + var extExpectedHighestTS uint64 + var expectedHighestTS uint32 + var tsCycles uint64 + if r.srNewest != nil { + newestPacketCount = r.srNewest.PacketCountExt + paddingOnlyDrops = r.srNewest.PaddingOnlyDrops + if newestPacketCount != 0 { + extExpectedHighestSN = r.sequenceNumber.GetExtendedStart() + newestPacketCount + if r.shouldDiscountPaddingOnlyDrops { + extExpectedHighestSN -= paddingOnlyDrops + } + expectedHighestSN = uint16(extExpectedHighestSN & 0xFFFF) + snCycles = extExpectedHighestSN & 0xFFFF_FFFF_FFFF_0000 + if sn-expectedHighestSN < (1<<15) && sn < expectedHighestSN { + snCycles += (1 << 16) + } + if snCycles != 0 && expectedHighestSN-sn < (1<<15) && expectedHighestSN < sn { + snCycles -= (1 << 16) + } + } + + newestTS = r.srNewest.RTPTimestampExt + extExpectedHighestTS = newestTS + expectedHighestTS = uint32(extExpectedHighestTS & 0xFFFF_FFFF) + tsCycles = extExpectedHighestTS & 0xFFFF_FFFF_0000_0000 + if ts-expectedHighestTS < (1<<31) && ts < expectedHighestTS { + tsCycles += (1 << 32) + } + if tsCycles != 0 && expectedHighestTS-ts < (1<<31) && expectedHighestTS < ts { + tsCycles -= (1 << 32) + } + } + r.sequenceNumber.ResetHighest(snCycles + uint64(sn) - 1) + r.timestamp.ResetHighest(tsCycles + uint64(ts)) + r.highestTime = packetTime + r.logger.Debugw( + "resync", + "newestPacketCount", newestPacketCount, + "paddingOnlyDrops", paddingOnlyDrops, + "extExpectedHighestSN", extExpectedHighestSN, + "expectedHighestSN", expectedHighestSN, + "snCycles", snCycles, + "rtpSN", sn, + "beforeExtHighestSN", extHighestSN, + "afterExtHighestSN", r.sequenceNumber.GetExtendedHighest(), + "newestTS", newestTS, + "extExpectedHighestTS", extExpectedHighestTS, + "expectedHighestTS", expectedHighestTS, + "tsCycles", tsCycles, + "rtpTS", ts, + "beforeExtHighestTS", extHighestTS, + "afterExtHighestTS", r.timestamp.GetExtendedHighest(), + ) +} + +func (r *RTPStatsReceiver) SetRtcpSenderReportData(srData *RTCPSenderReportData) { + r.lock.Lock() + defer r.lock.Unlock() + + if srData == nil || !r.initialized { + return + } + + // prevent against extreme case of anachronous sender reports + if r.srNewest != nil && r.srNewest.NTPTimestamp > srData.NTPTimestamp { + r.logger.Infow( + "received anachronous sender report", + "currentNTP", srData.NTPTimestamp.Time().String(), + "currentRTP", srData.RTPTimestamp, + "currentAt", srData.At.String(), + "lastNTP", r.srNewest.NTPTimestamp.Time().String(), + "lastRTP", r.srNewest.RTPTimestamp, + "lastAt", r.srNewest.At.String(), + ) + return + } + + tsCycles := uint64(0) + pcCycles := uint64(0) + if r.srNewest != nil { + tsCycles = r.srNewest.RTPTimestampExt & 0xFFFF_FFFF_0000_0000 + if (srData.RTPTimestamp-r.srNewest.RTPTimestamp) < (1<<31) && srData.RTPTimestamp < r.srNewest.RTPTimestamp { + tsCycles += (1 << 32) + } + + pcCycles = r.srNewest.PacketCountExt & 0xFFFF_FFFF_0000_0000 + if (srData.PacketCount-r.srNewest.PacketCount) < (1<<31) && srData.PacketCount < r.srNewest.PacketCount { + pcCycles += (1 << 32) + } + } + + srDataCopy := *srData + srDataCopy.RTPTimestampExt = uint64(srDataCopy.RTPTimestamp) + tsCycles + srDataCopy.PacketCountExt = uint64(srDataCopy.PacketCount) + pcCycles + + r.maybeAdjustFirstPacketTime(srDataCopy.RTPTimestampExt, r.timestamp.GetExtendedStart()) + + if r.srNewest != nil && srDataCopy.RTPTimestampExt < r.srNewest.RTPTimestampExt { + // This can happen when a track is replaced with a null and then restored - + // i. e. muting replacing with null and unmute restoring the original track. + // Under such a condition reset the sender reports to start from this point. + // Resetting will ensure sample rate calculations do not go haywire due to negative time. + r.logger.Infow( + "received sender report, out-of-order, resetting", + "prevTSExt", r.srNewest.RTPTimestampExt, + "prevRTP", r.srNewest.RTPTimestamp, + "prevNTP", r.srNewest.NTPTimestamp.Time().String(), + "prevAt", r.srNewest.At.String(), + "currTSExt", srDataCopy.RTPTimestampExt, + "currRTP", srDataCopy.RTPTimestamp, + "currNTP", srDataCopy.NTPTimestamp.Time().String(), + "currentAt", srDataCopy.At.String(), + ) + r.srFirst = nil + } + + r.srNewest = &srDataCopy + if r.srFirst == nil { + r.srFirst = &srDataCopy + } +} + +func (r *RTPStatsReceiver) GetRtcpSenderReportData() (srFirst *RTCPSenderReportData, srNewest *RTCPSenderReportData) { + r.lock.RLock() + defer r.lock.RUnlock() + + if r.srFirst != nil { + srFirstCopy := *r.srFirst + srFirst = &srFirstCopy + } + + if r.srNewest != nil { + srNewestCopy := *r.srNewest + srNewest = &srNewestCopy + } + return +} + +func (r *RTPStatsReceiver) GetRtcpReceptionReport(ssrc uint32, proxyFracLost uint8, snapshotID uint32) *rtcp.ReceptionReport { + r.lock.Lock() + defer r.lock.Unlock() + + extHighestSN := r.sequenceNumber.GetExtendedHighest() + then, now := r.getAndResetSnapshot(snapshotID, r.sequenceNumber.GetExtendedStart(), extHighestSN) + if now == nil || then == nil { + return nil + } + + packetsExpected := now.extStartSN - then.extStartSN + if packetsExpected > cNumSequenceNumbers { + r.logger.Warnw( + "too many packets expected in receiver report", + fmt.Errorf("start: %d, end: %d, expected: %d", then.extStartSN, now.extStartSN, packetsExpected), + ) + return nil + } + if packetsExpected == 0 { + return nil + } + + intervalStats := r.getIntervalStats(then.extStartSN, now.extStartSN, extHighestSN) + packetsLost := intervalStats.packetsLost + lossRate := float32(packetsLost) / float32(packetsExpected) + fracLost := uint8(lossRate * 256.0) + if proxyFracLost > fracLost { + fracLost = proxyFracLost + } + + lastSR := uint32(0) + dlsr := uint32(0) + if r.srNewest != nil { + lastSR = uint32(r.srNewest.NTPTimestamp >> 16) + if !r.srNewest.At.IsZero() { + delayMS := uint32(time.Since(r.srNewest.At).Milliseconds()) + dlsr = (delayMS / 1e3) << 16 + dlsr |= (delayMS % 1e3) * 65536 / 1000 + } + } + + return &rtcp.ReceptionReport{ + SSRC: ssrc, + FractionLost: fracLost, + TotalLost: uint32(r.packetsLost), + LastSequenceNumber: uint32(now.extStartSN), + Jitter: uint32(r.jitter), + LastSenderReport: lastSR, + Delay: dlsr, + } +} + +func (r *RTPStatsReceiver) DeltaInfo(snapshotID uint32) *RTPDeltaInfo { + r.lock.Lock() + defer r.lock.Unlock() + + return r.deltaInfo(snapshotID, r.sequenceNumber.GetExtendedStart(), r.sequenceNumber.GetExtendedHighest()) +} + +func (r *RTPStatsReceiver) ToString() string { + r.lock.RLock() + defer r.lock.RUnlock() + + return r.toString( + r.sequenceNumber.GetExtendedStart(), r.sequenceNumber.GetExtendedHighest(), r.timestamp.GetExtendedStart(), r.timestamp.GetExtendedHighest(), + r.packetsLost, + r.jitter, r.maxJitter, + ) +} + +func (r *RTPStatsReceiver) ToProto() *livekit.RTPStats { + r.lock.RLock() + defer r.lock.RUnlock() + + return r.toProto( + r.sequenceNumber.GetExtendedStart(), r.sequenceNumber.GetExtendedHighest(), r.timestamp.GetExtendedStart(), r.timestamp.GetExtendedHighest(), + r.packetsLost, + r.jitter, r.maxJitter, + ) +} + +// ---------------------------------- diff --git a/pkg/sfu/buffer/rtpstats_test.go b/pkg/sfu/buffer/rtpstats_receiver_test.go similarity index 69% rename from pkg/sfu/buffer/rtpstats_test.go rename to pkg/sfu/buffer/rtpstats_receiver_test.go index f5a4e004c..2dc1446f9 100644 --- a/pkg/sfu/buffer/rtpstats_test.go +++ b/pkg/sfu/buffer/rtpstats_receiver_test.go @@ -35,9 +35,9 @@ func getPacket(sn uint16, ts uint32, payloadSize int) *rtp.Packet { } } -func TestRTPStats(t *testing.T) { +func Test_RTPStatsReceiver(t *testing.T) { clockRate := uint32(90000) - r := NewRTPStats(RTPStatsParams{ + r := NewRTPStatsReceiver(RTPStatsParams{ ClockRate: clockRate, Logger: logger.GetLogger(), }) @@ -59,7 +59,15 @@ func TestRTPStats(t *testing.T) { timestamp += uint32(now.Sub(lastFrameTime).Seconds() * float64(clockRate)) for i := 0; i < packetsPerFrame; i++ { packet := getPacket(sequenceNumber, timestamp, packetSize) - r.Update(&packet.Header, len(packet.Payload), 0, time.Now()) + r.Update( + time.Now(), + packet.Header.SequenceNumber, + packet.Header.Timestamp, + packet.Header.Marker, + packet.Header.MarshalSize(), + len(packet.Payload), + 0, + ) if (sequenceNumber % 100) == 0 { jump := uint16(rand.Float64() * 120.0) sequenceNumber += jump @@ -77,9 +85,9 @@ func TestRTPStats(t *testing.T) { fmt.Printf("%s\n", r.ToString()) } -func TestRTPStats_Update(t *testing.T) { +func Test_RTPStatsReceiver_Update(t *testing.T) { clockRate := uint32(90000) - r := NewRTPStats(RTPStatsParams{ + r := NewRTPStatsReceiver(RTPStatsParams{ ClockRate: clockRate, Logger: logger.GetLogger(), }) @@ -87,7 +95,15 @@ func TestRTPStats_Update(t *testing.T) { sequenceNumber := uint16(rand.Float64() * float64(1<<16)) timestamp := uint32(rand.Float64() * float64(1<<32)) packet := getPacket(sequenceNumber, timestamp, 1000) - flowState := r.Update(&packet.Header, len(packet.Payload), 0, time.Now()) + flowState := r.Update( + time.Now(), + packet.Header.SequenceNumber, + packet.Header.Timestamp, + packet.Header.Marker, + packet.Header.MarshalSize(), + len(packet.Payload), + 0, + ) require.False(t, flowState.HasLoss) require.True(t, r.initialized) require.Equal(t, sequenceNumber, r.sequenceNumber.GetHighest()) @@ -99,7 +115,15 @@ func TestRTPStats_Update(t *testing.T) { sequenceNumber++ timestamp += 3000 packet = getPacket(sequenceNumber, timestamp, 1000) - flowState = r.Update(&packet.Header, len(packet.Payload), 0, time.Now()) + flowState = r.Update( + time.Now(), + packet.Header.SequenceNumber, + packet.Header.Timestamp, + packet.Header.Marker, + packet.Header.MarshalSize(), + len(packet.Payload), + 0, + ) require.False(t, flowState.HasLoss) require.Equal(t, sequenceNumber, r.sequenceNumber.GetHighest()) require.Equal(t, sequenceNumber, uint16(r.sequenceNumber.GetExtendedHighest())) @@ -108,7 +132,15 @@ func TestRTPStats_Update(t *testing.T) { // out-of-order packet = getPacket(sequenceNumber-10, timestamp-30000, 1000) - flowState = r.Update(&packet.Header, len(packet.Payload), 0, time.Now()) + flowState = r.Update( + time.Now(), + packet.Header.SequenceNumber, + packet.Header.Timestamp, + packet.Header.Marker, + packet.Header.MarshalSize(), + len(packet.Payload), + 0, + ) require.False(t, flowState.HasLoss) require.Equal(t, sequenceNumber, r.sequenceNumber.GetHighest()) require.Equal(t, sequenceNumber, uint16(r.sequenceNumber.GetExtendedHighest())) @@ -119,7 +151,15 @@ func TestRTPStats_Update(t *testing.T) { // duplicate packet = getPacket(sequenceNumber-10, timestamp-30000, 1000) - flowState = r.Update(&packet.Header, len(packet.Payload), 0, time.Now()) + flowState = r.Update( + time.Now(), + packet.Header.SequenceNumber, + packet.Header.Timestamp, + packet.Header.Marker, + packet.Header.MarshalSize(), + len(packet.Payload), + 0, + ) require.False(t, flowState.HasLoss) require.Equal(t, sequenceNumber, r.sequenceNumber.GetHighest()) require.Equal(t, sequenceNumber, uint16(r.sequenceNumber.GetExtendedHighest())) @@ -132,7 +172,15 @@ func TestRTPStats_Update(t *testing.T) { sequenceNumber += 10 timestamp += 30000 packet = getPacket(sequenceNumber, timestamp, 1000) - flowState = r.Update(&packet.Header, len(packet.Payload), 0, time.Now()) + flowState = r.Update( + time.Now(), + packet.Header.SequenceNumber, + packet.Header.Timestamp, + packet.Header.Marker, + packet.Header.MarshalSize(), + len(packet.Payload), + 0, + ) require.True(t, flowState.HasLoss) require.Equal(t, uint64(sequenceNumber-9), flowState.LossStartInclusive) require.Equal(t, uint64(sequenceNumber), flowState.LossEndExclusive) @@ -140,7 +188,15 @@ func TestRTPStats_Update(t *testing.T) { // out-of-order should decrement number of lost packets packet = getPacket(sequenceNumber-15, timestamp-45000, 1000) - flowState = r.Update(&packet.Header, len(packet.Payload), 0, time.Now()) + flowState = r.Update( + time.Now(), + packet.Header.SequenceNumber, + packet.Header.Timestamp, + packet.Header.Marker, + packet.Header.MarshalSize(), + len(packet.Payload), + 0, + ) require.False(t, flowState.HasLoss) require.Equal(t, sequenceNumber, r.sequenceNumber.GetHighest()) require.Equal(t, sequenceNumber, uint16(r.sequenceNumber.GetExtendedHighest())) @@ -149,7 +205,11 @@ func TestRTPStats_Update(t *testing.T) { require.Equal(t, uint64(3), r.packetsOutOfOrder) require.Equal(t, uint64(1), r.packetsDuplicate) require.Equal(t, uint64(16), r.packetsLost) - intervalStats := r.getIntervalStats(r.sequenceNumber.GetExtendedStart(), r.sequenceNumber.GetExtendedHighest()+1) + intervalStats := r.getIntervalStats( + r.sequenceNumber.GetExtendedStart(), + r.sequenceNumber.GetExtendedHighest()+1, + r.sequenceNumber.GetExtendedHighest(), + ) require.Equal(t, uint64(16), intervalStats.packetsLost) // test sequence number cache @@ -157,76 +217,100 @@ func TestRTPStats_Update(t *testing.T) { sequenceNumber += 2 timestamp += 6000 packet = getPacket(sequenceNumber, timestamp, 1000) - flowState = r.Update(&packet.Header, len(packet.Payload), 0, time.Now()) + flowState = r.Update( + time.Now(), + packet.Header.SequenceNumber, + packet.Header.Timestamp, + packet.Header.Marker, + packet.Header.MarshalSize(), + len(packet.Payload), + 0, + ) require.True(t, flowState.HasLoss) require.Equal(t, uint64(sequenceNumber-1), flowState.LossStartInclusive) require.Equal(t, uint64(sequenceNumber), flowState.LossEndExclusive) require.Equal(t, uint64(17), r.packetsLost) - expectedSnInfo := SnInfo{ + expectedSnInfo := snInfo{ hdrSize: 12, pktSize: 1012, isPaddingOnly: false, marker: false, isOutOfOrder: false, } - require.Equal(t, expectedSnInfo, r.snInfos[sequenceNumber&SnInfoMask]) + require.Equal(t, expectedSnInfo, r.snInfos[sequenceNumber&cSnInfoMask]) // out-of-order sequenceNumber-- timestamp -= 3000 packet = getPacket(sequenceNumber, timestamp, 999) - flowState = r.Update(&packet.Header, len(packet.Payload), 0, time.Now()) + flowState = r.Update( + time.Now(), + packet.Header.SequenceNumber, + packet.Header.Timestamp, + packet.Header.Marker, + packet.Header.MarshalSize(), + len(packet.Payload), + 0, + ) require.False(t, flowState.HasLoss) require.Equal(t, uint64(16), r.packetsLost) - expectedSnInfo = SnInfo{ + expectedSnInfo = snInfo{ hdrSize: 12, pktSize: 1011, isPaddingOnly: false, marker: false, isOutOfOrder: true, } - require.Equal(t, expectedSnInfo, r.snInfos[sequenceNumber&SnInfoMask]) + require.Equal(t, expectedSnInfo, r.snInfos[sequenceNumber&cSnInfoMask]) // check that last one is still fine - expectedSnInfo = SnInfo{ + expectedSnInfo = snInfo{ hdrSize: 12, pktSize: 1012, isPaddingOnly: false, marker: false, isOutOfOrder: false, } - require.Equal(t, expectedSnInfo, r.snInfos[(sequenceNumber+1)&SnInfoMask]) + require.Equal(t, expectedSnInfo, r.snInfos[(sequenceNumber+1)&cSnInfoMask]) // padding only sequenceNumber += 2 packet = getPacket(sequenceNumber, timestamp, 0) - flowState = r.Update(&packet.Header, len(packet.Payload), 25, time.Now()) + flowState = r.Update( + time.Now(), + packet.Header.SequenceNumber, + packet.Header.Timestamp, + packet.Header.Marker, + packet.Header.MarshalSize(), + len(packet.Payload), + 25, + ) require.False(t, flowState.HasLoss) require.Equal(t, uint64(16), r.packetsLost) - expectedSnInfo = SnInfo{ + expectedSnInfo = snInfo{ hdrSize: 12, pktSize: 37, isPaddingOnly: true, marker: false, isOutOfOrder: false, } - require.Equal(t, expectedSnInfo, r.snInfos[sequenceNumber&SnInfoMask]) + require.Equal(t, expectedSnInfo, r.snInfos[sequenceNumber&cSnInfoMask]) // check that last two are still fine - expectedSnInfo = SnInfo{ + expectedSnInfo = snInfo{ hdrSize: 12, pktSize: 1011, isPaddingOnly: false, marker: false, isOutOfOrder: true, } - require.Equal(t, expectedSnInfo, r.snInfos[(sequenceNumber-2)&SnInfoMask]) - expectedSnInfo = SnInfo{ + require.Equal(t, expectedSnInfo, r.snInfos[(sequenceNumber-2)&cSnInfoMask]) + expectedSnInfo = snInfo{ hdrSize: 12, pktSize: 1012, isPaddingOnly: false, marker: false, isOutOfOrder: false, } - require.Equal(t, expectedSnInfo, r.snInfos[(sequenceNumber-1)&SnInfoMask]) + require.Equal(t, expectedSnInfo, r.snInfos[(sequenceNumber-1)&cSnInfoMask]) r.Stop() } diff --git a/pkg/sfu/buffer/rtpstats_sender.go b/pkg/sfu/buffer/rtpstats_sender.go new file mode 100644 index 000000000..3bcf8cc48 --- /dev/null +++ b/pkg/sfu/buffer/rtpstats_sender.go @@ -0,0 +1,618 @@ +// Copyright 2023 LiveKit, Inc. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package buffer + +import ( + "errors" + "fmt" + "time" + + "github.com/pion/rtcp" + + "github.com/livekit/mediatransportutil" + "github.com/livekit/protocol/livekit" +) + +type senderSnapshot struct { + snapshot + extStartSNFromRR uint64 + packetsLostFromRR uint64 + maxJitterFromRR float64 +} + +type RTPStatsSender struct { + *rtpStatsBase + + extStartSN uint64 + extHighestSN uint64 + extHighestSNFromRR uint64 + + lastRRTime time.Time + lastRR rtcp.ReceptionReport + + extStartTS uint64 + extHighestTS uint64 + + packetsLostFromRR uint64 + + jitterFromRR float64 + maxJitterFromRR float64 + + nextSenderSnapshotID uint32 + senderSnapshots map[uint32]*senderSnapshot +} + +func NewRTPStatsSender(params RTPStatsParams) *RTPStatsSender { + return &RTPStatsSender{ + rtpStatsBase: newRTPStatsBase(params), + nextSenderSnapshotID: cFirstSnapshotID, + senderSnapshots: make(map[uint32]*senderSnapshot), + } +} + +func (r *RTPStatsSender) Seed(from *RTPStatsSender) { + r.lock.Lock() + defer r.lock.Unlock() + + if !r.seed(from.rtpStatsBase) { + return + } + + r.extStartSN = from.extStartSN + r.extHighestSN = from.extHighestSN + r.extHighestSNFromRR = from.extHighestSNFromRR + + r.lastRRTime = from.lastRRTime + r.lastRR = from.lastRR + + r.extStartTS = from.extStartTS + r.extHighestTS = from.extHighestTS + + r.packetsLostFromRR = from.packetsLostFromRR + + r.jitterFromRR = from.jitterFromRR + r.maxJitterFromRR = from.maxJitterFromRR + + r.nextSenderSnapshotID = from.nextSenderSnapshotID + for id, ss := range from.senderSnapshots { + ssCopy := *ss + r.senderSnapshots[id] = &ssCopy + } +} + +func (r *RTPStatsSender) NewSnapshotId() uint32 { + r.lock.Lock() + defer r.lock.Unlock() + + return r.newSnapshotID(r.extStartSN) +} + +func (r *RTPStatsSender) NewSenderSnapshotId() uint32 { + r.lock.Lock() + defer r.lock.Unlock() + + id := r.nextSenderSnapshotID + if r.initialized { + r.senderSnapshots[id] = &senderSnapshot{ + snapshot: snapshot{ + startTime: time.Now(), + extStartSN: r.extStartSN, + }, + extStartSNFromRR: r.extStartSN, + } + } + return id +} + +func (r *RTPStatsSender) Update( + packetTime time.Time, + extSequenceNumber uint64, + extTimestamp uint64, + marker bool, + hdrSize int, + payloadSize int, + paddingSize int, +) { + r.lock.Lock() + defer r.lock.Unlock() + + if !r.endTime.IsZero() { + return + } + + if !r.initialized { + if payloadSize == 0 { + // do not start on a padding only packet + return + } + + r.initialized = true + + r.startTime = time.Now() + + r.firstTime = packetTime + r.highestTime = packetTime + + r.extStartSN = extSequenceNumber + r.extHighestSN = extSequenceNumber + + r.extStartTS = extTimestamp + r.extHighestTS = extTimestamp + + // initialize snapshots if any + for i := uint32(cFirstSnapshotID); i < r.nextSnapshotID; i++ { + r.snapshots[i] = &snapshot{ + startTime: r.startTime, + extStartSN: r.extStartSN, + } + } + for i := uint32(cFirstSnapshotID); i < r.nextSenderSnapshotID; i++ { + r.senderSnapshots[i] = &senderSnapshot{ + snapshot: snapshot{ + startTime: r.startTime, + extStartSN: r.extStartSN, + }, + extStartSNFromRR: r.extStartSN, + } + } + + r.logger.Debugw( + "rtp sender stream start", + "startTime", r.startTime.String(), + "firstTime", r.firstTime.String(), + "startSN", r.extStartSN, + "startTS", r.extStartTS, + ) + } + + pktSize := uint64(hdrSize + payloadSize + paddingSize) + isDuplicate := false + gapSN := int64(extSequenceNumber - r.extHighestSN) + if gapSN <= 0 { // duplicate OR out-of-order + if payloadSize == 0 && extSequenceNumber < r.extStartSN { + // do not start on a padding only packet + return + } + + if extSequenceNumber < r.extStartSN { + r.packetsLost += r.extStartSN - extSequenceNumber + + // adjust start of snapshots + for _, s := range r.snapshots { + if s.extStartSN == r.extStartSN { + s.extStartSN = extSequenceNumber + } + } + for _, s := range r.senderSnapshots { + if s.extStartSN == r.extStartSN { + s.extStartSN = extSequenceNumber + } + } + + r.extStartSN = extSequenceNumber + } + + if extTimestamp < r.extStartTS { + r.extStartTS = extTimestamp + } + + if gapSN != 0 { + r.packetsOutOfOrder++ + } + + if !r.isSnInfoLost(extSequenceNumber, r.extHighestSN) { + r.bytesDuplicate += pktSize + r.headerBytesDuplicate += uint64(hdrSize) + r.packetsDuplicate++ + isDuplicate = true + } else { + r.packetsLost-- + r.setSnInfo(extSequenceNumber, r.extHighestSN, uint16(pktSize), uint16(hdrSize), uint16(payloadSize), marker, true) + } + } else { // in-order + // update gap histogram + r.updateGapHistogram(int(gapSN)) + + // update missing sequence numbers + r.clearSnInfos(r.extHighestSN+1, extSequenceNumber) + r.packetsLost += uint64(gapSN - 1) + + r.setSnInfo(extSequenceNumber, r.extHighestSN, uint16(pktSize), uint16(hdrSize), uint16(payloadSize), marker, false) + + if extTimestamp != r.extHighestTS { + // update only on first packet as same timestamp could be in multiple packets. + // NOTE: this may not be the first packet with this time stamp if there is packet loss. + r.highestTime = packetTime + } + r.extHighestSN = extSequenceNumber + r.extHighestTS = extTimestamp + } + + if !isDuplicate { + if payloadSize == 0 { + r.packetsPadding++ + r.bytesPadding += pktSize + r.headerBytesPadding += uint64(hdrSize) + } else { + r.bytes += pktSize + r.headerBytes += uint64(hdrSize) + + if marker { + r.frames++ + } + + jitter := r.updateJitter(extTimestamp, packetTime) + for _, s := range r.senderSnapshots { + if jitter > s.maxJitter { + s.maxJitter = jitter + } + } + } + } +} + +func (r *RTPStatsSender) GetTotalPacketsPrimary() uint64 { + r.lock.RLock() + defer r.lock.RUnlock() + + return r.getTotalPacketsPrimary(r.extStartSN, r.extHighestSN) +} + +func (r *RTPStatsSender) UpdateFromReceiverReport(rr rtcp.ReceptionReport) (rtt uint32, isRttChanged bool) { + r.lock.Lock() + defer r.lock.Unlock() + + if !r.initialized || !r.endTime.IsZero() { + return + } + + extHighestSNFromRR := r.extHighestSNFromRR&0xFFFF_FFFF_0000_0000 + uint64(rr.LastSequenceNumber) + if !r.lastRRTime.IsZero() { + if (rr.LastSequenceNumber-r.lastRR.LastSequenceNumber) < (1<<31) && rr.LastSequenceNumber < r.lastRR.LastSequenceNumber { + extHighestSNFromRR += (1 << 32) + } + } + if extHighestSNFromRR < r.extStartSN { + // it is possible that the `LastSequenceNumber` in the receiver report is before the starting + // sequence number when dummy packets are used to trigger Pion's OnTrack path. + return + } + + var err error + if r.srNewest != nil { + rtt, err = mediatransportutil.GetRttMs(&rr, r.srNewest.NTPTimestamp, r.srNewest.At) + if err == nil { + isRttChanged = rtt != r.rtt + } else { + if !errors.Is(err, mediatransportutil.ErrRttNotLastSenderReport) && !errors.Is(err, mediatransportutil.ErrRttNoLastSenderReport) { + r.logger.Warnw("error getting rtt", err) + } + } + } + + if r.lastRRTime.IsZero() || r.extHighestSNFromRR <= extHighestSNFromRR { + r.extHighestSNFromRR = extHighestSNFromRR + + packetsLostFromRR := r.packetsLostFromRR&0xFFFF_FFFF_0000_0000 + uint64(rr.TotalLost) + if (rr.TotalLost-r.lastRR.TotalLost) < (1<<31) && rr.TotalLost < r.lastRR.TotalLost { + packetsLostFromRR += (1 << 32) + } + r.packetsLostFromRR = packetsLostFromRR + + if isRttChanged { + r.rtt = rtt + if rtt > r.maxRtt { + r.maxRtt = rtt + } + } + + r.jitterFromRR = float64(rr.Jitter) + if r.jitterFromRR > r.maxJitterFromRR { + r.maxJitterFromRR = r.jitterFromRR + } + + // update snapshots + for _, s := range r.snapshots { + if isRttChanged && rtt > s.maxRtt { + s.maxRtt = rtt + } + } + for _, s := range r.senderSnapshots { + if isRttChanged && rtt > s.maxRtt { + s.maxRtt = rtt + } + + if r.jitterFromRR > s.maxJitterFromRR { + s.maxJitterFromRR = r.jitterFromRR + } + } + + r.lastRRTime = time.Now() + r.lastRR = rr + } else { + r.logger.Debugw( + fmt.Sprintf("receiver report potentially out of order, highestSN: existing: %d, received: %d", r.extHighestSNFromRR, rr.LastSequenceNumber), + "lastRRTime", r.lastRRTime, + "lastRR", r.lastRR, + "sinceLastRR", time.Since(r.lastRRTime), + "receivedRR", rr, + ) + } + return +} + +func (r *RTPStatsSender) LastReceiverReportTime() time.Time { + r.lock.RLock() + defer r.lock.RUnlock() + + return r.lastRRTime +} + +func (r *RTPStatsSender) MaybeAdjustFirstPacketTime(ets uint64) { + r.lock.Lock() + defer r.lock.Unlock() + + r.maybeAdjustFirstPacketTime(ets, r.extStartTS) +} + +func (r *RTPStatsSender) GetExpectedRTPTimestamp(at time.Time) (expectedTSExt uint64, err error) { + r.lock.RLock() + defer r.lock.RUnlock() + + if !r.initialized { + err = errors.New("uninitilaized") + return + } + + timeDiff := at.Sub(r.firstTime) + expectedRTPDiff := timeDiff.Nanoseconds() * int64(r.params.ClockRate) / 1e9 + expectedTSExt = r.extStartTS + uint64(expectedRTPDiff) + return +} + +func (r *RTPStatsSender) GetRtcpSenderReport(ssrc uint32, calculatedClockRate uint32) *rtcp.SenderReport { + r.lock.Lock() + defer r.lock.Unlock() + + if !r.initialized { + return nil + } + + // construct current time based on monotonic clock + timeSinceFirst := time.Since(r.firstTime) + now := r.firstTime.Add(timeSinceFirst) + nowNTP := mediatransportutil.ToNtpTime(now) + + timeSinceHighest := now.Sub(r.highestTime) + nowRTPExt := r.extHighestTS + uint64(timeSinceHighest.Nanoseconds()*int64(r.params.ClockRate)/1e9) + nowRTPExtUsingTime := nowRTPExt + nowRTP := uint32(nowRTPExt) + + // It is possible that publisher is pacing at a slower rate. + // That would make `highestTS` to be lagging the RTP time stamp in the RTCP Sender Report from publisher. + // Check for that using calculated clock rate and use the later time stamp if applicable. + var nowRTPExtUsingRate uint64 + if calculatedClockRate != 0 { + nowRTPExtUsingRate = r.extStartTS + uint64(float64(calculatedClockRate)*timeSinceFirst.Seconds()) + if nowRTPExtUsingRate > nowRTPExt { + nowRTPExt = nowRTPExtUsingRate + nowRTP = uint32(nowRTPExt) + } + } + + if r.srNewest != nil && nowRTPExt < r.srNewest.RTPTimestampExt { + // If report being generated is behind, use the time difference and + // clock rate of codec to produce next report. + // + // Current report could be behind due to the following + // - Publisher pacing + // - Due to above, report from publisher side is ahead of packet timestamps. + // Note that report will map wall clock to timestamp at capture time and happens before the pacer. + // - Pause/Mute followed by resume, some combination of events that could + // result in this module not having calculated clock rate of publisher side. + // - When the above happens, current will be generated using highestTS which could be behind. + // That could end up behind the last report's timestamp in extreme cases + r.logger.Infow( + "sending sender report, out-of-order, repairing", + "prevTSExt", r.srNewest.RTPTimestampExt, + "prevRTP", r.srNewest.RTPTimestamp, + "prevNTP", r.srNewest.NTPTimestamp.Time().String(), + "currTSExt", nowRTPExt, + "currRTP", nowRTP, + "currNTP", nowNTP.Time().String(), + "timeNow", time.Now().String(), + "firstTime", r.firstTime.String(), + "timeSinceFirst", timeSinceFirst, + "highestTime", r.highestTime.String(), + "timeSinceHighest", timeSinceHighest, + "nowRTPExtUsingTime", nowRTPExtUsingTime, + "calculatedClockRate", calculatedClockRate, + "nowRTPExtUsingRate", nowRTPExtUsingRate, + ) + ntpDiffSinceLast := nowNTP.Time().Sub(r.srNewest.NTPTimestamp.Time()) + nowRTPExt = r.srNewest.RTPTimestampExt + uint64(ntpDiffSinceLast.Seconds()*float64(r.params.ClockRate)) + nowRTP = uint32(nowRTPExt) + } + + r.srNewest = &RTCPSenderReportData{ + NTPTimestamp: nowNTP, + RTPTimestamp: nowRTP, + RTPTimestampExt: nowRTPExt, + At: now, + } + if r.srFirst == nil { + r.srFirst = r.srNewest + } + + return &rtcp.SenderReport{ + SSRC: ssrc, + NTPTime: uint64(nowNTP), + RTPTime: nowRTP, + PacketCount: uint32(r.getTotalPacketsPrimary(r.extStartSN, r.extHighestSN) + r.packetsDuplicate + r.packetsPadding), + OctetCount: uint32(r.bytes + r.bytesDuplicate + r.bytesPadding), + } +} + +func (r *RTPStatsSender) DeltaInfo(snapshotID uint32) *RTPDeltaInfo { + r.lock.Lock() + defer r.lock.Unlock() + + return r.deltaInfo(snapshotID, r.extStartSN, r.extHighestSN) +} + +func (r *RTPStatsSender) DeltaInfoSender(senderSnapshotID uint32) *RTPDeltaInfo { + r.lock.Lock() + defer r.lock.Unlock() + if r.lastRRTime.IsZero() { + return nil + } + + then, now := r.getAndResetSenderSnapshot(senderSnapshotID) + if now == nil || then == nil { + return nil + } + + startTime := then.startTime + endTime := now.startTime + + packetsExpected := now.extStartSNFromRR - then.extStartSNFromRR + if packetsExpected > cNumSequenceNumbers { + r.logger.Warnw( + "too many packets expected in delta (sender)", + fmt.Errorf("start: %d, end: %d, expected: %d", then.extStartSNFromRR, now.extStartSNFromRR, packetsExpected), + ) + return nil + } + if packetsExpected == 0 { + // not received RTCP RR (OR) publisher is not producing any data + return nil + } + + intervalStats := r.getIntervalStats(then.extStartSNFromRR, now.extStartSNFromRR, r.extHighestSN) + packetsLost := now.packetsLostFromRR - then.packetsLostFromRR + if int32(packetsLost) < 0 { + packetsLost = 0 + } + + if packetsLost > packetsExpected { + r.logger.Warnw( + "unexpected number of packets lost", + fmt.Errorf( + "start: %d, end: %d, expected: %d, lost: report: %d, interval: %d", + then.extStartSNFromRR, + now.extStartSNFromRR, + packetsExpected, + now.packetsLostFromRR-then.packetsLostFromRR, + intervalStats.packetsLost, + ), + ) + packetsLost = packetsExpected + } + + // discount jitter from publisher side + internal processing + maxJitter := then.maxJitterFromRR - then.maxJitter + if maxJitter < 0.0 { + maxJitter = 0.0 + } + maxJitterTime := maxJitter / float64(r.params.ClockRate) * 1e6 + + return &RTPDeltaInfo{ + StartTime: startTime, + Duration: endTime.Sub(startTime), + Packets: uint32(packetsExpected - intervalStats.packetsPadding), + Bytes: intervalStats.bytes, + HeaderBytes: intervalStats.headerBytes, + PacketsDuplicate: uint32(now.packetsDuplicate - then.packetsDuplicate), + BytesDuplicate: now.bytesDuplicate - then.bytesDuplicate, + HeaderBytesDuplicate: now.headerBytesDuplicate - then.headerBytesDuplicate, + PacketsPadding: uint32(intervalStats.packetsPadding), + BytesPadding: intervalStats.bytesPadding, + HeaderBytesPadding: intervalStats.headerBytesPadding, + PacketsLost: uint32(packetsLost), + PacketsMissing: uint32(intervalStats.packetsLost), + PacketsOutOfOrder: uint32(intervalStats.packetsOutOfOrder), + Frames: intervalStats.frames, + RttMax: then.maxRtt, + JitterMax: maxJitterTime, + Nacks: now.nacks - then.nacks, + Plis: now.plis - then.plis, + Firs: now.firs - then.firs, + } +} + +func (r *RTPStatsSender) ToString() string { + r.lock.RLock() + defer r.lock.RUnlock() + + return r.toString( + r.extStartSN, r.extHighestSN, r.extStartTS, r.extHighestTS, + r.packetsLostFromRR, + r.jitterFromRR, r.maxJitterFromRR, + ) +} + +func (r *RTPStatsSender) ToProto() *livekit.RTPStats { + r.lock.RLock() + defer r.lock.RUnlock() + + return r.toProto( + r.extStartSN, r.extHighestSN, r.extStartTS, r.extHighestTS, + r.packetsLostFromRR, + r.jitterFromRR, r.maxJitterFromRR, + ) +} + +func (r *RTPStatsSender) getAndResetSenderSnapshot(senderSnapshotID uint32) (*senderSnapshot, *senderSnapshot) { + if !r.initialized || r.lastRRTime.IsZero() { + return nil, nil + } + + then := r.senderSnapshots[senderSnapshotID] + if then == nil { + then = &senderSnapshot{ + snapshot: snapshot{ + startTime: r.startTime, + extStartSN: r.extStartSN, + }, + extStartSNFromRR: r.extStartSN, + } + r.senderSnapshots[senderSnapshotID] = then + } + + // snapshot now + r.senderSnapshots[senderSnapshotID] = &senderSnapshot{ + snapshot: snapshot{ + startTime: r.lastRRTime, + extStartSN: r.extHighestSN + 1, + packetsDuplicate: r.packetsDuplicate, + bytesDuplicate: r.bytesDuplicate, + headerBytesDuplicate: r.headerBytesDuplicate, + nacks: r.nacks, + plis: r.plis, + firs: r.firs, + maxJitter: r.jitter, + maxRtt: r.rtt, + }, + extStartSNFromRR: r.extHighestSNFromRR + 1, + packetsLostFromRR: r.packetsLostFromRR, + maxJitterFromRR: r.jitterFromRR, + } + // make a copy so that it can be used independently + now := *r.senderSnapshots[senderSnapshotID] + + return then, &now +} + +// ------------------------------------------------------------------- diff --git a/pkg/sfu/connectionquality/connectionstats.go b/pkg/sfu/connectionquality/connectionstats.go index 641290fa8..cfd91ee86 100644 --- a/pkg/sfu/connectionquality/connectionstats.go +++ b/pkg/sfu/connectionquality/connectionstats.go @@ -40,7 +40,7 @@ type ConnectionStatsParams struct { IncludeRTT bool IncludeJitter bool GetDeltaStats func() map[uint32]*buffer.StreamStatsWithLayers - GetDeltaStatsOverridden func() map[uint32]*buffer.StreamStatsWithLayers + GetDeltaStatsSender func() map[uint32]*buffer.StreamStatsWithLayers GetLastReceiverReportTime func() time.Time GetTotalPacketsSent func() uint64 Logger logger.Logger @@ -215,7 +215,7 @@ func (cs *ConnectionStats) updateScoreWithAggregate(agg *buffer.RTPDeltaInfo, at } func (cs *ConnectionStats) updateScoreFromReceiverReport(at time.Time) (float32, map[uint32]*buffer.StreamStatsWithLayers) { - if cs.params.GetDeltaStatsOverridden == nil || cs.params.GetLastReceiverReportTime == nil || cs.params.GetTotalPacketsSent == nil { + if cs.params.GetDeltaStatsSender == nil || cs.params.GetLastReceiverReportTime == nil || cs.params.GetTotalPacketsSent == nil { return MinMOS, nil } @@ -226,7 +226,7 @@ func (cs *ConnectionStats) updateScoreFromReceiverReport(at time.Time) (float32, return mos, nil } - streams := cs.params.GetDeltaStatsOverridden() + streams := cs.params.GetDeltaStatsSender() if len(streams) == 0 { // check for receiver report not received for a while marker := cs.params.GetLastReceiverReportTime() @@ -260,7 +260,7 @@ func (cs *ConnectionStats) updateScoreFromReceiverReport(at time.Time) (float32, } func (cs *ConnectionStats) updateScoreAt(at time.Time) (float32, map[uint32]*buffer.StreamStatsWithLayers) { - if cs.params.GetDeltaStatsOverridden != nil { + if cs.params.GetDeltaStatsSender != nil { // receiver report based quality scoring, use stats from receiver report for scoring return cs.updateScoreFromReceiverReport(at) } diff --git a/pkg/sfu/downtrack.go b/pkg/sfu/downtrack.go index 6f575500c..430e3e8e0 100644 --- a/pkg/sfu/downtrack.go +++ b/pkg/sfu/downtrack.go @@ -126,14 +126,14 @@ var ( // ------------------------------------------------------------------- type DownTrackState struct { - RTPStats *buffer.RTPStats - DeltaStatsOverriddenSnapshotId uint32 - ForwarderState ForwarderState + RTPStats *buffer.RTPStatsSender + DeltaStatsSenderSnapshotId uint32 + ForwarderState ForwarderState } func (d DownTrackState) String() string { - return fmt.Sprintf("DownTrackState{rtpStats: %s, deltaOverridden: %d, forwarder: %s}", - d.RTPStats.ToString(), d.DeltaStatsOverriddenSnapshotId, d.ForwarderState.String()) + return fmt.Sprintf("DownTrackState{rtpStats: %s, deltaSender: %d, forwarder: %s}", + d.RTPStats.ToString(), d.DeltaStatsSenderSnapshotId, d.ForwarderState.String()) } // ------------------------------------------------------------------- @@ -239,7 +239,7 @@ type DownTrack struct { bindAndConnectedOnce atomic.Bool writable atomic.Bool - rtpStats *buffer.RTPStats + rtpStats *buffer.RTPStatsSender totalRepeatedNACKs atomic.Uint32 @@ -247,8 +247,8 @@ type DownTrack struct { blankFramesGeneration atomic.Uint32 - connectionStats *connectionquality.ConnectionStats - deltaStatsOverriddenSnapshotId uint32 + connectionStats *connectionquality.ConnectionStats + deltaStatsSenderSnapshotId uint32 isNACKThrottled atomic.Bool @@ -304,17 +304,16 @@ func NewDownTrack(params DowntrackParams) (*DownTrack, error) { d.getExpectedRTPTimestamp, ) - d.rtpStats = buffer.NewRTPStats(buffer.RTPStatsParams{ - ClockRate: d.codec.ClockRate, - IsReceiverReportDriven: true, - Logger: params.Logger, + d.rtpStats = buffer.NewRTPStatsSender(buffer.RTPStatsParams{ + ClockRate: d.codec.ClockRate, + Logger: params.Logger, }) - d.deltaStatsOverriddenSnapshotId = d.rtpStats.NewSnapshotId() + d.deltaStatsSenderSnapshotId = d.rtpStats.NewSenderSnapshotId() d.connectionStats = connectionquality.NewConnectionStats(connectionquality.ConnectionStatsParams{ MimeType: codecs[0].MimeType, // LK-TODO have to notify on codec change IsFECEnabled: strings.EqualFold(codecs[0].MimeType, webrtc.MimeTypeOpus) && strings.Contains(strings.ToLower(codecs[0].SDPFmtpLine), "fec"), - GetDeltaStatsOverridden: d.getDeltaStatsOverridden, + GetDeltaStatsSender: d.getDeltaStatsSender, GetLastReceiverReportTime: func() time.Time { return d.rtpStats.LastReceiverReportTime() }, GetTotalPacketsSent: func() uint64 { return d.rtpStats.GetTotalPacketsPrimary() }, Logger: params.Logger.WithValues("direction", "down"), @@ -723,11 +722,13 @@ func (d *DownTrack) WriteRTP(extPkt *buffer.ExtPacket, layer int32) error { TransportWideExtID: uint8(d.transportWideExtID), WriteStream: d.writeStream, Metadata: sendPacketMetadata{ - layer: layer, - arrival: extPkt.Arrival, - isKeyFrame: extPkt.KeyFrame, - tp: tp, - pool: pool, + layer: layer, + arrival: extPkt.Arrival, + extSequenceNumber: tp.rtp.extSequenceNumber, + extTimestamp: tp.rtp.extTimestamp, + isKeyFrame: extPkt.KeyFrame, + tp: tp, + pool: pool, }, OnSent: d.packetSent, }) @@ -814,8 +815,10 @@ func (d *DownTrack) WritePaddingRTP(bytesToSend int, paddingOnMute bool, forceMa TransportWideExtID: uint8(d.transportWideExtID), WriteStream: d.writeStream, Metadata: sendPacketMetadata{ - isPadding: true, - disableCounter: true, + extSequenceNumber: snts[i].extSequenceNumber, + extTimestamp: snts[i].extTimestamp, + isPadding: true, + disableCounter: true, }, OnSent: d.packetSent, }) @@ -989,16 +992,16 @@ func (d *DownTrack) MaxLayer() buffer.VideoLayer { func (d *DownTrack) GetState() DownTrackState { dts := DownTrackState{ - RTPStats: d.rtpStats, - DeltaStatsOverriddenSnapshotId: d.deltaStatsOverriddenSnapshotId, - ForwarderState: d.forwarder.GetState(), + RTPStats: d.rtpStats, + DeltaStatsSenderSnapshotId: d.deltaStatsSenderSnapshotId, + ForwarderState: d.forwarder.GetState(), } return dts } func (d *DownTrack) SeedState(state DownTrackState) { d.rtpStats.Seed(state.RTPStats) - d.deltaStatsOverriddenSnapshotId = state.DeltaStatsOverriddenSnapshotId + d.deltaStatsSenderSnapshotId = state.DeltaStatsSenderSnapshotId d.forwarder.SeedState(state.ForwarderState) } @@ -1312,8 +1315,11 @@ func (d *DownTrack) writeBlankFrameRTP(duration float32, generation uint32) chan AbsSendTimeExtID: uint8(d.absSendTimeExtID), TransportWideExtID: uint8(d.transportWideExtID), WriteStream: d.writeStream, - Metadata: sendPacketMetadata{}, - OnSent: d.packetSent, + Metadata: sendPacketMetadata{ + extSequenceNumber: snts[i].extSequenceNumber, + extTimestamp: snts[i].extTimestamp, + }, + OnSent: d.packetSent, }) // only the first frame will need frameEndNeeded to close out the @@ -1539,20 +1545,20 @@ func (d *DownTrack) retransmitPackets(nacks []uint16) { nackMisses := uint32(0) numRepeatedNACKs := uint32(0) nackInfos := make([]NackInfo, 0, len(filtered)) - for _, meta := range d.sequencer.getPacketsMeta(filtered) { - if disallowedLayers[meta.layer] { + for _, epm := range d.sequencer.getExtPacketMetas(filtered) { + if disallowedLayers[epm.layer] { continue } nackAcks++ nackInfos = append(nackInfos, NackInfo{ - SequenceNumber: meta.targetSeqNo, - Timestamp: meta.timestamp, - Attempts: meta.nacked, + SequenceNumber: epm.targetSeqNo, + Timestamp: epm.timestamp, + Attempts: epm.nacked, }) pktBuff := *src - n, err := d.params.Receiver.ReadRTP(pktBuff, uint8(meta.layer), meta.sourceSeqNo) + n, err := d.params.Receiver.ReadRTP(pktBuff, uint8(epm.layer), epm.sourceSeqNo) if err != nil { if err == io.EOF { break @@ -1561,7 +1567,7 @@ func (d *DownTrack) retransmitPackets(nacks []uint16) { continue } - if meta.nacked > 1 { + if epm.nacked > 1 { numRepeatedNACKs++ } @@ -1570,15 +1576,15 @@ func (d *DownTrack) retransmitPackets(nacks []uint16) { d.params.Logger.Errorw("unmarshalling rtp packet failed in retransmit", err) continue } - pkt.Header.Marker = meta.marker - pkt.Header.SequenceNumber = meta.targetSeqNo - pkt.Header.Timestamp = meta.timestamp + pkt.Header.Marker = epm.marker + pkt.Header.SequenceNumber = epm.targetSeqNo + pkt.Header.Timestamp = epm.timestamp pkt.Header.SSRC = d.ssrc pkt.Header.PayloadType = d.payloadType var payload []byte pool := PacketFactory.Get().(*[]byte) - if d.mime == "video/vp8" && len(pkt.Payload) > 0 && len(meta.codecBytes) != 0 { + if d.mime == "video/vp8" && len(pkt.Payload) > 0 && len(epm.codecBytes) != 0 { var incomingVP8 buffer.VP8 if err = incomingVP8.Unmarshal(pkt.Payload); err != nil { d.params.Logger.Errorw("unmarshalling VP8 packet err", err) @@ -1586,7 +1592,7 @@ func (d *DownTrack) retransmitPackets(nacks []uint16) { continue } - payload = d.translateVP8PacketTo(&pkt, &incomingVP8, meta.codecBytes, pool) + payload = d.translateVP8PacketTo(&pkt, &incomingVP8, epm.codecBytes, pool) } if payload == nil { payload = (*pool)[:len(pkt.Payload)] @@ -1595,14 +1601,16 @@ func (d *DownTrack) retransmitPackets(nacks []uint16) { d.pacer.Enqueue(pacer.Packet{ Header: &pkt.Header, - Extensions: []pacer.ExtensionData{{ID: uint8(d.dependencyDescriptorExtID), Payload: meta.ddBytes}}, + Extensions: []pacer.ExtensionData{{ID: uint8(d.dependencyDescriptorExtID), Payload: epm.ddBytes}}, Payload: payload, AbsSendTimeExtID: uint8(d.absSendTimeExtID), TransportWideExtID: uint8(d.transportWideExtID), WriteStream: d.writeStream, Metadata: sendPacketMetadata{ - isRTX: true, - pool: pool, + extSequenceNumber: epm.extSequenceNumber, + extTimestamp: epm.extTimestamp, + isRTX: true, + pool: pool, }, OnSent: d.packetSent, }) @@ -1707,8 +1715,9 @@ func (d *DownTrack) deltaStats(ds *buffer.RTPDeltaInfo) map[uint32]*buffer.Strea return streamStats } -func (d *DownTrack) getDeltaStatsOverridden() map[uint32]*buffer.StreamStatsWithLayers { - return d.deltaStats(d.rtpStats.DeltaInfoOverridden(d.deltaStatsOverriddenSnapshotId)) +func (d *DownTrack) getDeltaStatsSender() map[uint32]*buffer.StreamStatsWithLayers { + return d.deltaStats(d.rtpStats.DeltaInfoSender(d.deltaStatsSenderSnapshotId)) + return nil } func (d *DownTrack) GetNackStats() (totalPackets uint32, totalRepeatedNACKs uint32) { @@ -1806,6 +1815,8 @@ func (d *DownTrack) sendSilentFrameOnMuteForOpus() { TransportWideExtID: uint8(d.transportWideExtID), WriteStream: d.writeStream, Metadata: sendPacketMetadata{ + extSequenceNumber: snts[i].extSequenceNumber, + extTimestamp: snts[i].extTimestamp, // although this is using empty frames, mark as padding as these are used to trigger Pion OnTrack only isPadding: true, }, @@ -1826,17 +1837,19 @@ func (d *DownTrack) HandleRTCPSenderReportData(_payloadType webrtc.PayloadType, } type sendPacketMetadata struct { - layer int32 - arrival time.Time - isKeyFrame bool - isRTX bool - isPadding bool - disableCounter bool - tp *TranslationParams - pool *[]byte + layer int32 + arrival time.Time + extSequenceNumber uint64 + extTimestamp uint64 + isKeyFrame bool + isRTX bool + isPadding bool + disableCounter bool + tp *TranslationParams + pool *[]byte } -func (d *DownTrack) packetSent(md interface{}, hdr *rtp.Header, payloadSize int, sendTime time.Time, sendError error) { +func (d *DownTrack) packetSent(md interface{}, marker bool, hdrSize int, payloadSize int, sendTime time.Time, sendError error) { spmd, ok := md.(sendPacketMetadata) if !ok { d.params.Logger.Errorw("invalid send packet metadata", nil) @@ -1853,7 +1866,7 @@ func (d *DownTrack) packetSent(md interface{}, hdr *rtp.Header, payloadSize int, if !spmd.disableCounter { // STREAM-ALLOCATOR-TODO: remove this stream allocator bytes counter once stream allocator changes fully to pull bytes counter - size := uint32(hdr.MarshalSize() + payloadSize) + size := uint32(hdrSize + payloadSize) d.streamAllocatorBytesCounter.Add(size) if spmd.isRTX { d.bytesRetransmitted.Add(size) @@ -1868,9 +1881,9 @@ func (d *DownTrack) packetSent(md interface{}, hdr *rtp.Header, payloadSize int, packetTime = sendTime } if spmd.isPadding { - d.rtpStats.Update(hdr, 0, payloadSize, packetTime) + d.rtpStats.Update(packetTime, spmd.extSequenceNumber, spmd.extTimestamp, marker, hdrSize, 0, payloadSize) } else { - d.rtpStats.Update(hdr, payloadSize, 0, packetTime) + d.rtpStats.Update(packetTime, spmd.extSequenceNumber, spmd.extTimestamp, marker, hdrSize, payloadSize, 0) } if spmd.isKeyFrame { @@ -1879,8 +1892,8 @@ func (d *DownTrack) packetSent(md interface{}, hdr *rtp.Header, payloadSize int, d.params.Logger.Debugw( "forwarded key frame", "layer", spmd.layer, - "rtpsn", hdr.SequenceNumber, - "rtpts", hdr.Timestamp, + "rtpsn", spmd.extSequenceNumber, + "rtpts", spmd.extTimestamp, ) } diff --git a/pkg/sfu/pacer/base.go b/pkg/sfu/pacer/base.go index 83e0efc43..a43ea6cd7 100644 --- a/pkg/sfu/pacer/base.go +++ b/pkg/sfu/pacer/base.go @@ -47,7 +47,7 @@ func (b *Base) SendPacket(p *Packet) (int, error) { var err error defer func() { if p.OnSent != nil { - p.OnSent(p.Metadata, p.Header, len(p.Payload), sendingAt, err) + p.OnSent(p.Metadata, p.Header.Marker, p.Header.MarshalSize(), len(p.Payload), sendingAt, err) } }() diff --git a/pkg/sfu/pacer/pacer.go b/pkg/sfu/pacer/pacer.go index 48b20efea..1464ea496 100644 --- a/pkg/sfu/pacer/pacer.go +++ b/pkg/sfu/pacer/pacer.go @@ -34,7 +34,7 @@ type Packet struct { TransportWideExtID uint8 WriteStream webrtc.TrackLocalWriter Metadata interface{} - OnSent func(md interface{}, sentHeader *rtp.Header, payloadSize int, sentTime time.Time, sendError error) + OnSent func(md interface{}, marker bool, hdrSize int, payloadSize int, sentTime time.Time, sendError error) } type Pacer interface { diff --git a/pkg/sfu/sequencer.go b/pkg/sfu/sequencer.go index 74dbd38f8..775c8d42a 100644 --- a/pkg/sfu/sequencer.go +++ b/pkg/sfu/sequencer.go @@ -72,6 +72,12 @@ type packetMeta struct { ddBytes []byte } +type extPacketMeta struct { + packetMeta + extSequenceNumber uint64 + extTimestamp uint64 +} + // Sequencer stores the packet sequence received by the down track type sequencer struct { sync.Mutex @@ -80,6 +86,7 @@ type sequencer struct { initialized bool extHighestSN uint64 snOffset uint64 + extHighestTS uint64 meta []packetMeta snRangeMap *utils.RangeMap[uint64, uint64] rtt uint32 @@ -126,6 +133,7 @@ func (s *sequencer) push( if !s.initialized { s.extHighestSN = extModifiedSN - 1 + s.extHighestTS = extModifiedTS s.updateSNOffset() } @@ -149,6 +157,10 @@ func (s *sequencer) push( } } + if int64(extModifiedTS-s.extHighestTS) >= 0 { + s.extHighestTS = extModifiedTS + } + slot := (extModifiedSN - snOffset) % uint64(s.size) s.meta[slot] = packetMeta{ sourceSeqNo: uint16(extIncomingSN), @@ -213,15 +225,16 @@ func (s *sequencer) pushPadding(extStartSNInclusive uint64, extEndSNInclusive ui s.updateSNOffset() } -func (s *sequencer) getPacketsMeta(seqNo []uint16) []packetMeta { +func (s *sequencer) getExtPacketMetas(seqNo []uint16) []extPacketMeta { s.Lock() defer s.Unlock() snOffset := uint64(0) var err error - packetsMeta := make([]packetMeta, 0, len(seqNo)) + extPacketMetas := make([]extPacketMeta, 0, len(seqNo)) refTime := s.getRefTime(time.Now()) highestSN := uint16(s.extHighestSN) + highestTS := uint32(s.extHighestTS) for _, sn := range seqNo { diff := highestSN - sn if diff > (1 << 15) { @@ -258,14 +271,22 @@ func (s *sequencer) getPacketsMeta(seqNo []uint16) []packetMeta { meta.nacked++ meta.lastNack = refTime - pm := *meta - pm.codecBytes = append([]byte{}, meta.codecBytes...) - pm.ddBytes = append([]byte{}, meta.ddBytes...) - packetsMeta = append(packetsMeta, pm) + extTS := uint64(meta.timestamp) + (s.extHighestTS & 0xFFFF_FFFF_FFFF_0000) + if meta.timestamp > highestTS { + extTS -= (1 << 32) + } + epm := extPacketMeta{ + packetMeta: *meta, + extSequenceNumber: extSN, + extTimestamp: extTS, + } + epm.codecBytes = append([]byte{}, meta.codecBytes...) + epm.ddBytes = append([]byte{}, meta.ddBytes...) + extPacketMetas = append(extPacketMetas, epm) } } - return packetsMeta + return extPacketMetas } func (s *sequencer) getRefTime(at time.Time) uint32 { diff --git a/pkg/sfu/sequencer_test.go b/pkg/sfu/sequencer_test.go index 900248992..c71bd039f 100644 --- a/pkg/sfu/sequencer_test.go +++ b/pkg/sfu/sequencer_test.go @@ -36,41 +36,45 @@ func Test_sequencer(t *testing.T) { seq.push(time.Now(), 518, 518+uint64(off), 123, true, 2, nil, nil) req := []uint16{57, 58, 62, 63, 513, 514, 515, 516, 517} - res := seq.getPacketsMeta(req) + res := seq.getExtPacketMetas(req) // nothing should be returned as not enough time has elapsed since sending packet require.Equal(t, 0, len(res)) time.Sleep((ignoreRetransmission + 10) * time.Millisecond) - res = seq.getPacketsMeta(req) + res = seq.getExtPacketMetas(req) require.Equal(t, len(req), len(res)) for i, val := range res { require.Equal(t, val.targetSeqNo, req[i]) require.Equal(t, val.sourceSeqNo, req[i]-off) require.Equal(t, val.layer, int8(2)) + require.Equal(t, val.extSequenceNumber, uint64(req[i])) + require.Equal(t, val.extTimestamp, uint64(123)) } - res = seq.getPacketsMeta(req) + res = seq.getExtPacketMetas(req) require.Equal(t, 0, len(res)) time.Sleep((ignoreRetransmission + 10) * time.Millisecond) - res = seq.getPacketsMeta(req) + res = seq.getExtPacketMetas(req) require.Equal(t, len(req), len(res)) for i, val := range res { require.Equal(t, val.targetSeqNo, req[i]) require.Equal(t, val.sourceSeqNo, req[i]-off) require.Equal(t, val.layer, int8(2)) + require.Equal(t, val.extSequenceNumber, uint64(req[i])) + require.Equal(t, val.extTimestamp, uint64(123)) } seq.push(time.Now(), 521, 521+uint64(off), 123, true, 1, nil, nil) - m := seq.getPacketsMeta([]uint16{521 + off}) + m := seq.getExtPacketMetas([]uint16{521 + off}) require.Equal(t, 0, len(m)) time.Sleep((ignoreRetransmission + 10) * time.Millisecond) - m = seq.getPacketsMeta([]uint16{521 + off}) + m = seq.getExtPacketMetas([]uint16{521 + off}) require.Equal(t, 1, len(m)) seq.push(time.Now(), 505, 505+uint64(off), 123, false, 1, nil, nil) - m = seq.getPacketsMeta([]uint16{505 + off}) + m = seq.getExtPacketMetas([]uint16{505 + off}) require.Equal(t, 0, len(m)) time.Sleep((ignoreRetransmission + 10) * time.Millisecond) - m = seq.getPacketsMeta([]uint16{505 + off}) + m = seq.getExtPacketMetas([]uint16{505 + off}) require.Equal(t, 1, len(m)) } @@ -148,7 +152,7 @@ func Test_sequencer_getNACKSeqNo_exclusion(t *testing.T) { } time.Sleep((ignoreRetransmission + 10) * time.Millisecond) - g := n.getPacketsMeta(tt.args.seqNo) + g := n.getExtPacketMetas(tt.args.seqNo) var got []uint16 for _, sn := range g { got = append(got, sn.sourceSeqNo) @@ -163,7 +167,7 @@ func Test_sequencer_getNACKSeqNo_exclusion(t *testing.T) { } } if !reflect.DeepEqual(got, tt.want) { - t.Errorf("getPacketsMeta() = %v, want %v", got, tt.want) + t.Errorf("getExtPacketMetas() = %v, want %v", got, tt.want) } }) } @@ -242,7 +246,7 @@ func Test_sequencer_getNACKSeqNo_no_exclusion(t *testing.T) { } time.Sleep((ignoreRetransmission + 10) * time.Millisecond) - g := n.getPacketsMeta(tt.args.seqNo) + g := n.getExtPacketMetas(tt.args.seqNo) var got []uint16 for _, sn := range g { got = append(got, sn.sourceSeqNo) @@ -257,7 +261,7 @@ func Test_sequencer_getNACKSeqNo_no_exclusion(t *testing.T) { } } if !reflect.DeepEqual(got, tt.want) { - t.Errorf("getPacketsMeta() = %v, want %v", got, tt.want) + t.Errorf("getExtPacketMetas() = %v, want %v", got, tt.want) } }) }