dandri/livekit
1
0
Fork 0
mirror of https://github.com/livekit/livekit.git synced 2026-07-18 13:56:32 +00:00
Code Issues Packages Projects Releases Wiki Activity

Log more info when adjusting start timestamp. (#2722)

Browse Source 
Seeing some large time stamp jump in relay down track once in a while.
Logging more details on time stamp switch to learn more.
This commit is contained in:
Raja Subramanian
2024-05-23 13:03:26 +05:30
committed by GitHub
parent 86b15c2e82
commit 96cb829b84
2 changed files with 65 additions and 92 deletions
Download Patch File Download Diff File Expand all files Collapse all files
pkg/sfu/buffer/rtpstats_receiver.go
+25 -41
View File
@@ -169,27 +169,32 @@ func (r *RTPStatsReceiver) Update(
pktSize := uint64(hdrSize + payloadSize + paddingSize)
gapSN := int64(resSN.ExtendedVal - resSN.PreExtendedHighest)
getLoggingFields := func() []interface{} {
return []interface{}{
"extStartSN", r.sequenceNumber.GetExtendedStart(),
"extHighestSN", r.sequenceNumber.GetExtendedHighest(),
"extStartTS", r.timestamp.GetExtendedStart(),
"extHighestTS", r.timestamp.GetExtendedHighest(),
"firstTime", r.firstTime.String(),
"highestTime", r.highestTime.String(),
"prevSN", resSN.PreExtendedHighest,
"currSN", resSN.ExtendedVal,
"gapSN", gapSN,
"prevTS", resTS.PreExtendedHighest,
"currTS", resTS.ExtendedVal,
"gapTS", resTS.ExtendedVal - resTS.PreExtendedHighest,
"packetTime", packetTime.String(),
"sequenceNumber", sequenceNumber,
"timestamp", timestamp,
"marker", marker,
"hdrSize", hdrSize,
"payloadSize", payloadSize,
"paddingSize", paddingSize,
}
}
if gapSN <= 0 { // duplicate OR out-of-order
if -gapSN >= cNumSequenceNumbers/2 {
r.logger.Warnw(
"large sequence number gap negative", nil,
"extStartSN", r.sequenceNumber.GetExtendedStart(),
"extHighestSN", r.sequenceNumber.GetExtendedHighest(),
"extStartTS", r.timestamp.GetExtendedStart(),
"extHighestTS", r.timestamp.GetExtendedHighest(),
"firstTime", r.firstTime.String(),
"highestTime", r.highestTime.String(),
"prev", resSN.PreExtendedHighest,
"curr", resSN.ExtendedVal,
"gap", gapSN,
"packetTime", packetTime.String(),
"sequenceNumber", sequenceNumber,
"timestamp", timestamp,
"marker", marker,
"hdrSize", hdrSize,
"payloadSize", payloadSize,
"paddingSize", paddingSize,
)
r.logger.Warnw("large sequence number gap negative", nil, getLoggingFields()...)
}
if gapSN != 0 {
@@ -213,28 +218,7 @@ func (r *RTPStatsReceiver) Update(
flowState.ExtTimestamp = resTS.ExtendedVal
} else { // in-order
if gapSN >= cNumSequenceNumbers/2 || resTS.ExtendedVal < resTS.PreExtendedHighest {
r.logger.Warnw(
"large sequence number gap OR time reversed", nil,
"extStartSN", r.sequenceNumber.GetExtendedStart(),
"extHighestSN", r.sequenceNumber.GetExtendedHighest(),
"extStartTS", r.timestamp.GetExtendedStart(),
"extHighestTS", r.timestamp.GetExtendedHighest(),
"firstTime", r.firstTime.String(),
"highestTime", r.highestTime.String(),
"prevSN", resSN.PreExtendedHighest,
"currSN", resSN.ExtendedVal,
"gapSN", gapSN,
"prevTS", resTS.PreExtendedHighest,
"currTS", resTS.ExtendedVal,
"gapTS", resTS.ExtendedVal-resTS.PreExtendedHighest,
"packetTime", packetTime.String(),
"sequenceNumber", sequenceNumber,
"timestamp", timestamp,
"marker", marker,
"hdrSize", hdrSize,
"payloadSize", payloadSize,
"paddingSize", paddingSize,
)
r.logger.Warnw("large sequence number gap OR time reversed", nil, getLoggingFields()...)
}
// update gap histogram
pkg/sfu/buffer/rtpstats_sender.go
+40 -51
View File
@@ -284,33 +284,38 @@ func (r *RTPStatsSender) Update(
pktSize := uint64(hdrSize + payloadSize + paddingSize)
isDuplicate := false
gapSN := int64(extSequenceNumber - r.extHighestSN)
getLoggingFields := func() []interface{} {
return []interface{}{
"extStartSN", r.extStartSN,
"extHighestSN", r.extHighestSN,
"extStartTS", r.extStartTS,
"extHighestTS", r.extHighestTS,
"firstTime", r.firstTime.String(),
"highestTime", r.highestTime.String(),
"prevSN", r.extHighestSN,
"currSN", extSequenceNumber,
"gapSN", gapSN,
"prevTS", r.extHighestTS,
"currTS", extTimestamp,
"gapTS", extTimestamp - r.extHighestTS,
"packetTime", packetTime.String(),
"sequenceNumber", extSequenceNumber,
"timestamp", extTimestamp,
"marker", marker,
"hdrSize", hdrSize,
"payloadSize", payloadSize,
"paddingSize", paddingSize,
"firstSR", r.srFirst,
"lastSR", r.srNewest,
}
}
if gapSN <= 0 { // duplicate OR out-of-order
if payloadSize == 0 && extSequenceNumber < r.extStartSN {
// do not start on a padding only packet
return
}
if -gapSN >= cNumSequenceNumbers/2 {
r.logger.Warnw(
"large sequence number gap negative", nil,
"extStartSN", r.extStartSN,
"extHighestSN", r.extHighestSN,
"extStartTS", r.extStartTS,
"extHighestTS", r.extHighestTS,
"firstTime", r.firstTime.String(),
"highestTime", r.highestTime.String(),
"prev", r.extHighestSN,
"curr", extSequenceNumber,
"gap", gapSN,
"packetTime", packetTime.String(),
"sequenceNumber", extSequenceNumber,
"timestamp", extTimestamp,
"marker", marker,
"hdrSize", hdrSize,
"payloadSize", payloadSize,
"paddingSize", paddingSize,
"firstSR", r.srFirst,
"lastSR", r.srNewest,
)
r.logger.Warnw("large sequence number gap negative", nil, getLoggingFields()...)
}
if extSequenceNumber < r.extStartSN {
@@ -335,10 +340,12 @@ func (r *RTPStatsSender) Update(
r.logger.Infow(
"adjusting start sequence number",
"snBefore", r.extStartSN,
"snAfter", extSequenceNumber,
"tsBefore", r.extStartTS,
"tsAfter", extTimestamp,
append(getLoggingFields(),
"snBefore", r.extStartSN,
"snAfter", extSequenceNumber,
"tsBefore", r.extStartTS,
"tsAfter", extTimestamp,
)...,
)
r.extStartSN = extSequenceNumber
}
@@ -357,28 +364,8 @@ func (r *RTPStatsSender) Update(
r.setSnInfo(extSequenceNumber, r.extHighestSN, uint16(pktSize), uint8(hdrSize), uint16(payloadSize), marker, true)
}
} else { // in-order
if gapSN >= cNumSequenceNumbers/2 {
r.logger.Warnw(
"large sequence number gap", nil,
"extStartSN", r.extStartSN,
"extHighestSN", r.extHighestSN,
"extStartTS", r.extStartTS,
"extHighestTS", r.extHighestTS,
"firstTime", r.firstTime.String(),
"highestTime", r.highestTime.String(),
"prev", r.extHighestSN,
"curr", extSequenceNumber,
"gap", gapSN,
"packetTime", packetTime.String(),
"sequenceNumber", extSequenceNumber,
"timestamp", extTimestamp,
"marker", marker,
"hdrSize", hdrSize,
"payloadSize", payloadSize,
"paddingSize", paddingSize,
"firstSR", r.srFirst,
"lastSR", r.srNewest,
)
if gapSN >= cNumSequenceNumbers/2 || extTimestamp < r.extHighestTS {
r.logger.Warnw("large sequence number gap OR time reversed", nil, getLoggingFields()...)
}
// update gap histogram
@@ -396,10 +383,12 @@ func (r *RTPStatsSender) Update(
if extTimestamp < r.extStartTS {
r.logger.Infow(
"adjusting start timestamp",
"snBefore", r.extStartSN,
"snAfter", extSequenceNumber,
"tsBefore", r.extStartTS,
"tsAfter", extTimestamp,
append(getLoggingFields(),
"snBefore", r.extStartSN,
"snAfter", extSequenceNumber,
"tsBefore", r.extStartTS,
"tsAfter", extTimestamp,
)...,
)
r.extStartTS = extTimestamp
}