From 32af15dc8036d583a98a3875cec66a48d1ef66d0 Mon Sep 17 00:00:00 2001 From: Raja Subramanian Date: Mon, 21 Aug 2023 13:20:40 +0530 Subject: [PATCH] Log RTP stream start time and more details when adjusting first packet time. (#1983) Trying to understand first packet time jumps on migration. --- pkg/sfu/buffer/rtpstats.go | 15 ++++++++++++++- 1 file changed, 14 insertions(+), 1 deletion(-) diff --git a/pkg/sfu/buffer/rtpstats.go b/pkg/sfu/buffer/rtpstats.go index d99954bb0..120285129 100644 --- a/pkg/sfu/buffer/rtpstats.go +++ b/pkg/sfu/buffer/rtpstats.go @@ -402,6 +402,14 @@ func (r *RTPStats) Update(rtph *rtp.Header, payloadSize int, paddingSize int, pa extStartSNOverridden: r.extStartSN, } } + + r.logger.Debugw( + "rtp stream start", + "startTime", r.startTime.String(), + "firstTime", r.firstTime.String(), + "startSN", r.extStartSN, + "startTS", r.extStartTS, + ) } if r.resyncOnNextPacket { @@ -529,7 +537,7 @@ func (r *RTPStats) maybeAdjustStart(rtph *rtp.Header, pktSize uint64, hdrSize ui r.tsCycles++ } r.logger.Infow( - "adjusting starting sequence number", + "adjusting start", "snBefore", snBeforeAdjust, "snAfter", r.extStartSN, "snCyles", r.cycles, @@ -817,8 +825,13 @@ func (r *RTPStats) maybeAdjustFirstPacketTime(ts uint32) { 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), + "nowTS", ts, + "extStartTS", r.extStartTS, ) if r.firstTime.Sub(firstTime) > firstPacketTimeAdjustThreshold { r.logger.Infow("first packet time adjustment too big, ignoring",