diff --git a/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.js b/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.js index b90712a873d..f1369c8e4ec 100644 --- a/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.js +++ b/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.js @@ -122,6 +122,21 @@ function PeerConnectionAnalyzer() { video: true, } + // Total number of entries ever pushed to _rtcStats[kind] since last reset. + // Used together with _loggedUpToRtcStatsTotal to determine which entries + // are new and have not been logged yet. + this._totalRtcStatsAdded = { + audio: 0, + video: 0, + } + // Value of _totalRtcStatsAdded[kind] after the last _logStats call. + // -1 is a sentinel meaning "not currently in a bad quality period"; on the + // next bad check all current _rtcStats entries will be logged. + this._loggedUpToRtcStatsTotal = { + audio: -1, + video: -1, + } + this._peerConnection = null this._peerDirection = null this._peerType = null @@ -221,6 +236,9 @@ PeerConnectionAnalyzer.prototype = { this._packetsPerSecond[kind].reset() this._timestamps[kind].reset() this._timestampsForLogs[kind].reset() + + this._totalRtcStatsAdded[kind] = 0 + this._loggedUpToRtcStatsTotal[kind] = -1 }, _handleIceConnectionStateChanged() { @@ -303,6 +321,7 @@ PeerConnectionAnalyzer.prototype = { this._rtcStats[kind].shift() } this._rtcStats[kind].push([]) + this._totalRtcStatsAdded[kind]++ } if (this._peerDirection === PEER_DIRECTION.SENDER) { @@ -317,6 +336,10 @@ PeerConnectionAnalyzer.prototype = { if (this._analysisEnabled.video) { this._setConnectionQualityVideo(this._calculateConnectionQualityVideo()) } + + for (const kind of ['audio', 'video']) { + this._logRemainingStatsIfQualityRecovered(kind) + } }, _processSenderStats(stats) { @@ -767,6 +790,15 @@ PeerConnectionAnalyzer.prototype = { }, _logStats(kind, message) { + const logAll = this._loggedUpToRtcStatsTotal[kind] === -1 + const newCount = logAll + ? this._rtcStats[kind].length + : this._totalRtcStatsAdded[kind] - this._loggedUpToRtcStatsTotal[kind] + + if (!logAll && newCount === 0) { + return + } + const tag = this._getLogTag(kind) if (message) { @@ -780,20 +812,53 @@ PeerConnectionAnalyzer.prototype = { console.debug('%s: Round trip time: %s', tag, this._roundTripTime[kind].toString()) console.debug('%s: Timestamps: %s', tag, this._timestampsForLogs[kind].toString()) - this._logRtcStats(tag, kind) + const startTotal = logAll ? 0 : this._loggedUpToRtcStatsTotal[kind] + const startIdx = Math.max(0, this._rtcStats[kind].length - newCount) + this._logRtcStats(tag, kind, startTotal, startIdx) + + this._loggedUpToRtcStatsTotal[kind] = this._totalRtcStatsAdded[kind] }, - _logRtcStats(tag, kind) { - this._rtcStats[kind].forEach((rtcStats, i) => { + // Logs entries in _rtcStats[kind] from startIdx onwards, using startTotal + // as the base for the printed entry indices so they are consistent across + // calls even as old entries are shifted out of the sliding window. + _logRtcStats(tag, kind, startTotal = 0, startIdx = 0) { + for (let i = startIdx; i < this._rtcStats[kind].length; i++) { + const rtcStats = this._rtcStats[kind][i] + const logIdx = startTotal + (i - startIdx) + if (!rtcStats.length) { - console.debug('%s: %i: no matching type', tag, i) - return + console.debug('%s: %i: no matching type', tag, logIdx) + continue } rtcStats.forEach((rtcStat, j) => { - console.debug('%s: %i-%i: %s', tag, i, j, JSON.stringify(rtcStat)) + console.debug('%s: %i-%i: %s', tag, logIdx, j, JSON.stringify(rtcStat)) }) - }) + } + }, + + // Called after each quality update. If quality has recovered from a bad + // period, flushes any rtcStats entries collected since the last _logStats + // call so that no data is missing in the logs. + _logRemainingStatsIfQualityRecovered(kind) { + if (this._loggedUpToRtcStatsTotal[kind] === -1) { + return + } + + const quality = this._connectionQuality[kind] + if (quality === CONNECTION_QUALITY.VERY_BAD || quality === CONNECTION_QUALITY.NO_TRANSMITTED_DATA) { + return + } + + const newCount = this._totalRtcStatsAdded[kind] - this._loggedUpToRtcStatsTotal[kind] + if (newCount > 0) { + const tag = this._getLogTag(kind) + const startIdx = Math.max(0, this._rtcStats[kind].length - newCount) + this._logRtcStats(tag, kind, this._loggedUpToRtcStatsTotal[kind], startIdx) + } + + this._loggedUpToRtcStatsTotal[kind] = -1 }, } diff --git a/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.spec.js b/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.spec.js index 21cddeb10dc..4cecf0893d9 100644 --- a/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.spec.js +++ b/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.spec.js @@ -3793,7 +3793,7 @@ describe('PeerConnectionAnalyzer', () => { expect(consoleDebugMock).toHaveBeenNthCalledWith(6, '%s: Round trip time: %s', tag, '[0.2, 0.3, 0.4]') expect(consoleDebugMock).toHaveBeenNthCalledWith(7, '%s: Timestamps: %s', tag, '[0, 1250, 1000]') expect(logRtcStatsMock).toHaveBeenCalledTimes(1) - expect(logRtcStatsMock).toHaveBeenCalledWith(tag, kind) + expect(logRtcStatsMock).toHaveBeenCalledWith(tag, kind, 0, 0) }) test.each([ @@ -3821,7 +3821,7 @@ describe('PeerConnectionAnalyzer', () => { expect(consoleDebugMock).toHaveBeenNthCalledWith(6, '%s: Round trip time: %s', tag, '[0.2, 0.3, 0.4]') expect(consoleDebugMock).toHaveBeenNthCalledWith(7, '%s: Timestamps: %s', tag, '[0, 1250, 1000]') expect(logRtcStatsMock).toHaveBeenCalledTimes(1) - expect(logRtcStatsMock).toHaveBeenCalledWith(tag, kind) + expect(logRtcStatsMock).toHaveBeenCalledWith(tag, kind, 0, 0) }) describe('log RTC stats', () => { @@ -3830,154 +3830,189 @@ describe('PeerConnectionAnalyzer', () => { peerConnection._setConnectionState('connected') }) - test.each([ + describe.each([ ['sender', 'audio'], ['sender', 'video'], ])('%s, %s', async (name, kind) => { - // Different reports contain different types and values in each - // type (and some of them not really applicable for a sender), - // even if in a real world scenario they would be consistent - // between reports. - peerConnection.getStats - .mockResolvedValueOnce(newRTCStatsReport([ - { type: 'outbound-rtp', kind, packetsSent: 50, timestamp: 10000 }, - { type: 'remote-inbound-rtp', kind, packetsReceived: 45, timestamp: 10000, packetsLost: 5, roundTripTime: 0.1 }, - ])) - .mockResolvedValueOnce(newRTCStatsReport([ - { type: 'outbound-rtp', kind, packetsSent: 100, timestamp: 11000 }, - { type: 'remote-inbound-rtp', kind, packetsReceived: 90, timestamp: 11000, packetsLost: 10, roundTripTime: 0.2 }, - ])) - .mockResolvedValueOnce(newRTCStatsReport([ - { type: 'outbound-rtp', kind, id: '67890', packetsSent: 150, timestamp: 11950, rid: 'h' }, - { type: 'outbound-rtp', kind, id: 'abcde', packetsSent: 80, timestamp: 11950, rid: 'm' }, - { type: 'remote-inbound-rtp', kind, localId: '67890', packetsReceived: 135, timestamp: 11950, packetsLost: 15, roundTripTime: 0.1 }, - { type: 'remote-inbound-rtp', kind, localId: 'abcde', packetsReceived: 72, timestamp: 11950, packetsLost: 8, roundTripTime: 0.1 }, - ])) - .mockResolvedValueOnce(newRTCStatsReport([ - { type: 'outbound-rtp', kind, packetsSent: 200, timestamp: 13020 }, - { type: 'remote-inbound-rtp', kind, packetsReceived: 180, timestamp: 13020, packetsLost: 20, roundTripTime: 0.15, jitter: 0.007 }, - ])) - .mockResolvedValueOnce(newRTCStatsReport([ - { type: 'local-candidate', candidateType: 'host', protocol: 'udp' }, - ])) - .mockResolvedValueOnce(newRTCStatsReport([ - { type: 'outbound-rtp', kind, packetsSent: 300, timestamp: 14985 }, - { type: 'remote-inbound-rtp', kind, packetsReceived: 270, timestamp: 14985, packetsLost: 30, roundTripTime: 0.3 }, - { type: 'inbound-rtp', kind, packetsReceived: 26, timestamp: 14985, packetsLost: 2 }, - { type: 'remote-outbound-rtp', kind, packetsSent: 28, timestamp: 14985 }, - ])) - .mockResolvedValueOnce(newRTCStatsReport([ - { type: 'candidate-pair', byteReceived: 2120, bytesSent: 63820, timestamp: 16010 }, - { type: 'outbound-rtp', kind, packetsSent: 350, timestamp: 16010 }, - { type: 'remote-inbound-rtp', kind, packetsReceived: 315, timestamp: 16010, packetsLost: 35, roundTripTime: 0.25 }, - ])) - .mockResolvedValueOnce(newRTCStatsReport([ - { type: 'outbound-rtp', kind, bytesSent: 64042, packetsSent: 400, timestamp: 17000 }, - { type: 'remote-inbound-rtp', kind, packetsReceived: 360, timestamp: 17000, packetsLost: 40, roundTripTime: 0.15 }, - ])) - .mockResolvedValueOnce(newRTCStatsReport([ - { type: 'outbound-rtp', kind, packetsSent: 450, timestamp: 17990, codecId: '123456' }, - { type: 'remote-inbound-rtp', kind, packetsReceived: 405, timestamp: 17990, packetsLost: 45, roundTripTime: 0.2 }, - ])) - - peerConnectionAnalyzer.setPeerConnection(peerConnection, PEER_DIRECTION.SENDER) - - vi.advanceTimersByTime(9000) - // Force the promises returning the stats to be executed. - await null - - const tag = 'PeerConnectionAnalyzer: ' + kind - - peerConnectionAnalyzer._logRtcStats(tag, kind) - - expect(consoleDebugMock).toHaveBeenCalledTimes(15) - expect(consoleDebugMock).toHaveBeenNthCalledWith(1, '%s: %i-%i: %s', tag, 0, 0, '{"type":"outbound-rtp","kind":"' + kind + '","id":"67890","packetsSent":150,"timestamp":11950,"rid":"h"}') - expect(consoleDebugMock).toHaveBeenNthCalledWith(2, '%s: %i-%i: %s', tag, 0, 1, '{"type":"outbound-rtp","kind":"' + kind + '","id":"abcde","packetsSent":80,"timestamp":11950,"rid":"m"}') - expect(consoleDebugMock).toHaveBeenNthCalledWith(3, '%s: %i-%i: %s', tag, 0, 2, '{"type":"remote-inbound-rtp","kind":"' + kind + '","localId":"67890","packetsReceived":135,"timestamp":11950,"packetsLost":15,"roundTripTime":0.1}') - expect(consoleDebugMock).toHaveBeenNthCalledWith(4, '%s: %i-%i: %s', tag, 0, 3, '{"type":"remote-inbound-rtp","kind":"' + kind + '","localId":"abcde","packetsReceived":72,"timestamp":11950,"packetsLost":8,"roundTripTime":0.1}') - expect(consoleDebugMock).toHaveBeenNthCalledWith(5, '%s: %i-%i: %s', tag, 1, 0, '{"type":"outbound-rtp","kind":"' + kind + '","packetsSent":200,"timestamp":13020}') - expect(consoleDebugMock).toHaveBeenNthCalledWith(6, '%s: %i-%i: %s', tag, 1, 1, '{"type":"remote-inbound-rtp","kind":"' + kind + '","packetsReceived":180,"timestamp":13020,"packetsLost":20,"roundTripTime":0.15,"jitter":0.007}') - expect(consoleDebugMock).toHaveBeenNthCalledWith(7, '%s: %i: no matching type', tag, 2) - expect(consoleDebugMock).toHaveBeenNthCalledWith(8, '%s: %i-%i: %s', tag, 3, 0, '{"type":"outbound-rtp","kind":"' + kind + '","packetsSent":300,"timestamp":14985}') - expect(consoleDebugMock).toHaveBeenNthCalledWith(9, '%s: %i-%i: %s', tag, 3, 1, '{"type":"remote-inbound-rtp","kind":"' + kind + '","packetsReceived":270,"timestamp":14985,"packetsLost":30,"roundTripTime":0.3}') - expect(consoleDebugMock).toHaveBeenNthCalledWith(10, '%s: %i-%i: %s', tag, 4, 0, '{"type":"outbound-rtp","kind":"' + kind + '","packetsSent":350,"timestamp":16010}') - expect(consoleDebugMock).toHaveBeenNthCalledWith(11, '%s: %i-%i: %s', tag, 4, 1, '{"type":"remote-inbound-rtp","kind":"' + kind + '","packetsReceived":315,"timestamp":16010,"packetsLost":35,"roundTripTime":0.25}') - expect(consoleDebugMock).toHaveBeenNthCalledWith(12, '%s: %i-%i: %s', tag, 5, 0, '{"type":"outbound-rtp","kind":"' + kind + '","bytesSent":64042,"packetsSent":400,"timestamp":17000}') - expect(consoleDebugMock).toHaveBeenNthCalledWith(13, '%s: %i-%i: %s', tag, 5, 1, '{"type":"remote-inbound-rtp","kind":"' + kind + '","packetsReceived":360,"timestamp":17000,"packetsLost":40,"roundTripTime":0.15}') - expect(consoleDebugMock).toHaveBeenNthCalledWith(14, '%s: %i-%i: %s', tag, 6, 0, '{"type":"outbound-rtp","kind":"' + kind + '","packetsSent":450,"timestamp":17990,"codecId":"123456"}') - expect(consoleDebugMock).toHaveBeenNthCalledWith(15, '%s: %i-%i: %s', tag, 6, 1, '{"type":"remote-inbound-rtp","kind":"' + kind + '","packetsReceived":405,"timestamp":17990,"packetsLost":45,"roundTripTime":0.2}') + beforeEach(async () => { + // Different reports contain different types and values in each + // type (and some of them not really applicable for a sender), + // even if in a real world scenario they would be consistent + // between reports. + peerConnection.getStats + .mockResolvedValueOnce(newRTCStatsReport([ + { type: 'outbound-rtp', kind, packetsSent: 50, timestamp: 10000 }, + { type: 'remote-inbound-rtp', kind, packetsReceived: 45, timestamp: 10000, packetsLost: 5, roundTripTime: 0.1 }, + ])) + .mockResolvedValueOnce(newRTCStatsReport([ + { type: 'outbound-rtp', kind, packetsSent: 100, timestamp: 11000 }, + { type: 'remote-inbound-rtp', kind, packetsReceived: 90, timestamp: 11000, packetsLost: 10, roundTripTime: 0.2 }, + ])) + .mockResolvedValueOnce(newRTCStatsReport([ + { type: 'outbound-rtp', kind, id: '67890', packetsSent: 150, timestamp: 11950, rid: 'h' }, + { type: 'outbound-rtp', kind, id: 'abcde', packetsSent: 80, timestamp: 11950, rid: 'm' }, + { type: 'remote-inbound-rtp', kind, localId: '67890', packetsReceived: 135, timestamp: 11950, packetsLost: 15, roundTripTime: 0.1 }, + { type: 'remote-inbound-rtp', kind, localId: 'abcde', packetsReceived: 72, timestamp: 11950, packetsLost: 8, roundTripTime: 0.1 }, + ])) + .mockResolvedValueOnce(newRTCStatsReport([ + { type: 'outbound-rtp', kind, packetsSent: 200, timestamp: 13020 }, + { type: 'remote-inbound-rtp', kind, packetsReceived: 180, timestamp: 13020, packetsLost: 20, roundTripTime: 0.15, jitter: 0.007 }, + ])) + .mockResolvedValueOnce(newRTCStatsReport([ + { type: 'local-candidate', candidateType: 'host', protocol: 'udp' }, + ])) + .mockResolvedValueOnce(newRTCStatsReport([ + { type: 'outbound-rtp', kind, packetsSent: 300, timestamp: 14985 }, + { type: 'remote-inbound-rtp', kind, packetsReceived: 270, timestamp: 14985, packetsLost: 30, roundTripTime: 0.3 }, + { type: 'inbound-rtp', kind, packetsReceived: 26, timestamp: 14985, packetsLost: 2 }, + { type: 'remote-outbound-rtp', kind, packetsSent: 28, timestamp: 14985 }, + ])) + .mockResolvedValueOnce(newRTCStatsReport([ + { type: 'candidate-pair', byteReceived: 2120, bytesSent: 63820, timestamp: 16010 }, + { type: 'outbound-rtp', kind, packetsSent: 350, timestamp: 16010 }, + { type: 'remote-inbound-rtp', kind, packetsReceived: 315, timestamp: 16010, packetsLost: 35, roundTripTime: 0.25 }, + ])) + .mockResolvedValueOnce(newRTCStatsReport([ + { type: 'outbound-rtp', kind, bytesSent: 64042, packetsSent: 400, timestamp: 17000 }, + { type: 'remote-inbound-rtp', kind, packetsReceived: 360, timestamp: 17000, packetsLost: 40, roundTripTime: 0.15 }, + ])) + .mockResolvedValueOnce(newRTCStatsReport([ + { type: 'outbound-rtp', kind, packetsSent: 450, timestamp: 17990, codecId: '123456' }, + { type: 'remote-inbound-rtp', kind, packetsReceived: 405, timestamp: 17990, packetsLost: 45, roundTripTime: 0.2 }, + ])) + + peerConnectionAnalyzer.setPeerConnection(peerConnection, PEER_DIRECTION.SENDER) + + vi.advanceTimersByTime(9000) + // Force the promises returning the stats to be executed. + await null + }) + + test('full stats', () => { + const tag = 'PeerConnectionAnalyzer: ' + kind + + peerConnectionAnalyzer._logRtcStats(tag, kind, 42, 0) + + expect(consoleDebugMock).toHaveBeenCalledTimes(15) + expect(consoleDebugMock).toHaveBeenNthCalledWith(1, '%s: %i-%i: %s', tag, 42, 0, '{"type":"outbound-rtp","kind":"' + kind + '","id":"67890","packetsSent":150,"timestamp":11950,"rid":"h"}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(2, '%s: %i-%i: %s', tag, 42, 1, '{"type":"outbound-rtp","kind":"' + kind + '","id":"abcde","packetsSent":80,"timestamp":11950,"rid":"m"}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(3, '%s: %i-%i: %s', tag, 42, 2, '{"type":"remote-inbound-rtp","kind":"' + kind + '","localId":"67890","packetsReceived":135,"timestamp":11950,"packetsLost":15,"roundTripTime":0.1}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(4, '%s: %i-%i: %s', tag, 42, 3, '{"type":"remote-inbound-rtp","kind":"' + kind + '","localId":"abcde","packetsReceived":72,"timestamp":11950,"packetsLost":8,"roundTripTime":0.1}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(5, '%s: %i-%i: %s', tag, 43, 0, '{"type":"outbound-rtp","kind":"' + kind + '","packetsSent":200,"timestamp":13020}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(6, '%s: %i-%i: %s', tag, 43, 1, '{"type":"remote-inbound-rtp","kind":"' + kind + '","packetsReceived":180,"timestamp":13020,"packetsLost":20,"roundTripTime":0.15,"jitter":0.007}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(7, '%s: %i: no matching type', tag, 44) + expect(consoleDebugMock).toHaveBeenNthCalledWith(8, '%s: %i-%i: %s', tag, 45, 0, '{"type":"outbound-rtp","kind":"' + kind + '","packetsSent":300,"timestamp":14985}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(9, '%s: %i-%i: %s', tag, 45, 1, '{"type":"remote-inbound-rtp","kind":"' + kind + '","packetsReceived":270,"timestamp":14985,"packetsLost":30,"roundTripTime":0.3}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(10, '%s: %i-%i: %s', tag, 46, 0, '{"type":"outbound-rtp","kind":"' + kind + '","packetsSent":350,"timestamp":16010}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(11, '%s: %i-%i: %s', tag, 46, 1, '{"type":"remote-inbound-rtp","kind":"' + kind + '","packetsReceived":315,"timestamp":16010,"packetsLost":35,"roundTripTime":0.25}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(12, '%s: %i-%i: %s', tag, 47, 0, '{"type":"outbound-rtp","kind":"' + kind + '","bytesSent":64042,"packetsSent":400,"timestamp":17000}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(13, '%s: %i-%i: %s', tag, 47, 1, '{"type":"remote-inbound-rtp","kind":"' + kind + '","packetsReceived":360,"timestamp":17000,"packetsLost":40,"roundTripTime":0.15}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(14, '%s: %i-%i: %s', tag, 48, 0, '{"type":"outbound-rtp","kind":"' + kind + '","packetsSent":450,"timestamp":17990,"codecId":"123456"}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(15, '%s: %i-%i: %s', tag, 48, 1, '{"type":"remote-inbound-rtp","kind":"' + kind + '","packetsReceived":405,"timestamp":17990,"packetsLost":45,"roundTripTime":0.2}') + }) + + test('partial stats', () => { + const tag = 'PeerConnectionAnalyzer: ' + kind + + peerConnectionAnalyzer._logRtcStats(tag, kind, 46, 4) + + expect(consoleDebugMock).toHaveBeenCalledTimes(6) + expect(consoleDebugMock).toHaveBeenNthCalledWith(1, '%s: %i-%i: %s', tag, 46, 0, '{"type":"outbound-rtp","kind":"' + kind + '","packetsSent":350,"timestamp":16010}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(2, '%s: %i-%i: %s', tag, 46, 1, '{"type":"remote-inbound-rtp","kind":"' + kind + '","packetsReceived":315,"timestamp":16010,"packetsLost":35,"roundTripTime":0.25}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(3, '%s: %i-%i: %s', tag, 47, 0, '{"type":"outbound-rtp","kind":"' + kind + '","bytesSent":64042,"packetsSent":400,"timestamp":17000}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(4, '%s: %i-%i: %s', tag, 47, 1, '{"type":"remote-inbound-rtp","kind":"' + kind + '","packetsReceived":360,"timestamp":17000,"packetsLost":40,"roundTripTime":0.15}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(5, '%s: %i-%i: %s', tag, 48, 0, '{"type":"outbound-rtp","kind":"' + kind + '","packetsSent":450,"timestamp":17990,"codecId":"123456"}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(6, '%s: %i-%i: %s', tag, 48, 1, '{"type":"remote-inbound-rtp","kind":"' + kind + '","packetsReceived":405,"timestamp":17990,"packetsLost":45,"roundTripTime":0.2}') + }) }) - test.each([ + describe.each([ ['receiver', 'audio'], ['receiver', 'video'], ])('%s, %s', async (name, kind) => { - // Different reports contain different types and values in each - // type (and some of them not really applicable for a receiver), - // even if in a real world scenario they would be consistent - // between reports. - peerConnection.getStats - .mockResolvedValueOnce(newRTCStatsReport([ - { type: 'inbound-rtp', kind, packetsReceived: 45, timestamp: 10000, packetsLost: 5 }, - { type: 'remote-outbound-rtp', kind, packetsSent: 50, timestamp: 10000 }, - ])) - .mockResolvedValueOnce(newRTCStatsReport([ - { type: 'inbound-rtp', kind, packetsReceived: 90, timestamp: 11000, packetsLost: 10 }, - { type: 'remote-outbound-rtp', kind, packetsSent: 100, timestamp: 11000 }, - ])) - .mockResolvedValueOnce(newRTCStatsReport([ - { type: 'inbound-rtp', kind, id: '67890', packetsReceived: 135, timestamp: 11950, packetsLost: 15 }, - { type: 'remote-outbound-rtp', kind, localId: '67890', packetsSent: 150, timestamp: 11950 }, - ])) - .mockResolvedValueOnce(newRTCStatsReport([ - { type: 'inbound-rtp', kind, packetsReceived: 180, timestamp: 13020, packetsLost: 20, jitter: 0.007 }, - { type: 'remote-outbound-rtp', kind, packetsSent: 200, timestamp: 13020 }, - ])) - .mockResolvedValueOnce(newRTCStatsReport([ - { type: 'local-candidate', candidateType: 'host', protocol: 'udp' }, - ])) - .mockResolvedValueOnce(newRTCStatsReport([ - { type: 'inbound-rtp', kind, packetsReceived: 270, timestamp: 14985, packetsLost: 30 }, - { type: 'remote-outbound-rtp', kind, packetsSent: 300, timestamp: 14985 }, - { type: 'outbound-rtp', kind, packetsSent: 28, timestamp: 14985 }, - { type: 'remote-inbound-rtp', kind, packetsReceived: 26, timestamp: 14985, packetsLost: 2, roundTripTime: 0.3 }, - ])) - .mockResolvedValueOnce(newRTCStatsReport([ - { type: 'candidate-pair', byteReceived: 2120, bytesSent: 63820, timestamp: 16010 }, - { type: 'inbound-rtp', kind, packetsReceived: 315, timestamp: 16010, packetsLost: 35 }, - { type: 'remote-outbound-rtp', kind, packetsSent: 350, timestamp: 16010 }, - ])) - .mockResolvedValueOnce(newRTCStatsReport([ - { type: 'inbound-rtp', kind, bytesReceived: 64042, packetsReceived: 400, timestamp: 17000 }, - ])) - .mockResolvedValueOnce(newRTCStatsReport([ - { type: 'inbound-rtp', kind, packetsReceived: 405, timestamp: 17990, packetsLost: 45, codecId: '123456' }, - { type: 'remote-outbound-rtp', kind, packetsSent: 450, timestamp: 17990 }, - ])) - - peerConnectionAnalyzer.setPeerConnection(peerConnection, PEER_DIRECTION.RECEIVER) - - vi.advanceTimersByTime(9000) - // Force the promises returning the stats to be executed. - await null - - const tag = 'PeerConnectionAnalyzer: ' + kind + ': ' - - peerConnectionAnalyzer._logRtcStats(tag, kind) - - expect(consoleDebugMock).toHaveBeenCalledTimes(12) - expect(consoleDebugMock).toHaveBeenNthCalledWith(1, '%s: %i-%i: %s', tag, 0, 0, '{"type":"inbound-rtp","kind":"' + kind + '","id":"67890","packetsReceived":135,"timestamp":11950,"packetsLost":15}') - expect(consoleDebugMock).toHaveBeenNthCalledWith(2, '%s: %i-%i: %s', tag, 0, 1, '{"type":"remote-outbound-rtp","kind":"' + kind + '","localId":"67890","packetsSent":150,"timestamp":11950}') - expect(consoleDebugMock).toHaveBeenNthCalledWith(3, '%s: %i-%i: %s', tag, 1, 0, '{"type":"inbound-rtp","kind":"' + kind + '","packetsReceived":180,"timestamp":13020,"packetsLost":20,"jitter":0.007}') - expect(consoleDebugMock).toHaveBeenNthCalledWith(4, '%s: %i-%i: %s', tag, 1, 1, '{"type":"remote-outbound-rtp","kind":"' + kind + '","packetsSent":200,"timestamp":13020}') - expect(consoleDebugMock).toHaveBeenNthCalledWith(5, '%s: %i: no matching type', tag, 2) - expect(consoleDebugMock).toHaveBeenNthCalledWith(6, '%s: %i-%i: %s', tag, 3, 0, '{"type":"inbound-rtp","kind":"' + kind + '","packetsReceived":270,"timestamp":14985,"packetsLost":30}') - expect(consoleDebugMock).toHaveBeenNthCalledWith(7, '%s: %i-%i: %s', tag, 3, 1, '{"type":"remote-outbound-rtp","kind":"' + kind + '","packetsSent":300,"timestamp":14985}') - expect(consoleDebugMock).toHaveBeenNthCalledWith(8, '%s: %i-%i: %s', tag, 4, 0, '{"type":"inbound-rtp","kind":"' + kind + '","packetsReceived":315,"timestamp":16010,"packetsLost":35}') - expect(consoleDebugMock).toHaveBeenNthCalledWith(9, '%s: %i-%i: %s', tag, 4, 1, '{"type":"remote-outbound-rtp","kind":"' + kind + '","packetsSent":350,"timestamp":16010}') - expect(consoleDebugMock).toHaveBeenNthCalledWith(10, '%s: %i-%i: %s', tag, 5, 0, '{"type":"inbound-rtp","kind":"' + kind + '","bytesReceived":64042,"packetsReceived":400,"timestamp":17000}') - expect(consoleDebugMock).toHaveBeenNthCalledWith(11, '%s: %i-%i: %s', tag, 6, 0, '{"type":"inbound-rtp","kind":"' + kind + '","packetsReceived":405,"timestamp":17990,"packetsLost":45,"codecId":"123456"}') - expect(consoleDebugMock).toHaveBeenNthCalledWith(12, '%s: %i-%i: %s', tag, 6, 1, '{"type":"remote-outbound-rtp","kind":"' + kind + '","packetsSent":450,"timestamp":17990}') + beforeEach(async () => { + // Different reports contain different types and values in each + // type (and some of them not really applicable for a receiver), + // even if in a real world scenario they would be consistent + // between reports. + peerConnection.getStats + .mockResolvedValueOnce(newRTCStatsReport([ + { type: 'inbound-rtp', kind, packetsReceived: 45, timestamp: 10000, packetsLost: 5 }, + { type: 'remote-outbound-rtp', kind, packetsSent: 50, timestamp: 10000 }, + ])) + .mockResolvedValueOnce(newRTCStatsReport([ + { type: 'inbound-rtp', kind, packetsReceived: 90, timestamp: 11000, packetsLost: 10 }, + { type: 'remote-outbound-rtp', kind, packetsSent: 100, timestamp: 11000 }, + ])) + .mockResolvedValueOnce(newRTCStatsReport([ + { type: 'inbound-rtp', kind, id: '67890', packetsReceived: 135, timestamp: 11950, packetsLost: 15 }, + { type: 'remote-outbound-rtp', kind, localId: '67890', packetsSent: 150, timestamp: 11950 }, + ])) + .mockResolvedValueOnce(newRTCStatsReport([ + { type: 'inbound-rtp', kind, packetsReceived: 180, timestamp: 13020, packetsLost: 20, jitter: 0.007 }, + { type: 'remote-outbound-rtp', kind, packetsSent: 200, timestamp: 13020 }, + ])) + .mockResolvedValueOnce(newRTCStatsReport([ + { type: 'local-candidate', candidateType: 'host', protocol: 'udp' }, + ])) + .mockResolvedValueOnce(newRTCStatsReport([ + { type: 'inbound-rtp', kind, packetsReceived: 270, timestamp: 14985, packetsLost: 30 }, + { type: 'remote-outbound-rtp', kind, packetsSent: 300, timestamp: 14985 }, + { type: 'outbound-rtp', kind, packetsSent: 28, timestamp: 14985 }, + { type: 'remote-inbound-rtp', kind, packetsReceived: 26, timestamp: 14985, packetsLost: 2, roundTripTime: 0.3 }, + ])) + .mockResolvedValueOnce(newRTCStatsReport([ + { type: 'candidate-pair', byteReceived: 2120, bytesSent: 63820, timestamp: 16010 }, + { type: 'inbound-rtp', kind, packetsReceived: 315, timestamp: 16010, packetsLost: 35 }, + { type: 'remote-outbound-rtp', kind, packetsSent: 350, timestamp: 16010 }, + ])) + .mockResolvedValueOnce(newRTCStatsReport([ + { type: 'inbound-rtp', kind, bytesReceived: 64042, packetsReceived: 400, timestamp: 17000 }, + ])) + .mockResolvedValueOnce(newRTCStatsReport([ + { type: 'inbound-rtp', kind, packetsReceived: 405, timestamp: 17990, packetsLost: 45, codecId: '123456' }, + { type: 'remote-outbound-rtp', kind, packetsSent: 450, timestamp: 17990 }, + ])) + + peerConnectionAnalyzer.setPeerConnection(peerConnection, PEER_DIRECTION.RECEIVER) + + vi.advanceTimersByTime(9000) + // Force the promises returning the stats to be executed. + await null + }) + + test('full stats', () => { + const tag = 'PeerConnectionAnalyzer: ' + kind + ': ' + + peerConnectionAnalyzer._logRtcStats(tag, kind, 42, 0) + + expect(consoleDebugMock).toHaveBeenCalledTimes(12) + expect(consoleDebugMock).toHaveBeenNthCalledWith(1, '%s: %i-%i: %s', tag, 42, 0, '{"type":"inbound-rtp","kind":"' + kind + '","id":"67890","packetsReceived":135,"timestamp":11950,"packetsLost":15}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(2, '%s: %i-%i: %s', tag, 42, 1, '{"type":"remote-outbound-rtp","kind":"' + kind + '","localId":"67890","packetsSent":150,"timestamp":11950}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(3, '%s: %i-%i: %s', tag, 43, 0, '{"type":"inbound-rtp","kind":"' + kind + '","packetsReceived":180,"timestamp":13020,"packetsLost":20,"jitter":0.007}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(4, '%s: %i-%i: %s', tag, 43, 1, '{"type":"remote-outbound-rtp","kind":"' + kind + '","packetsSent":200,"timestamp":13020}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(5, '%s: %i: no matching type', tag, 44) + expect(consoleDebugMock).toHaveBeenNthCalledWith(6, '%s: %i-%i: %s', tag, 45, 0, '{"type":"inbound-rtp","kind":"' + kind + '","packetsReceived":270,"timestamp":14985,"packetsLost":30}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(7, '%s: %i-%i: %s', tag, 45, 1, '{"type":"remote-outbound-rtp","kind":"' + kind + '","packetsSent":300,"timestamp":14985}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(8, '%s: %i-%i: %s', tag, 46, 0, '{"type":"inbound-rtp","kind":"' + kind + '","packetsReceived":315,"timestamp":16010,"packetsLost":35}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(9, '%s: %i-%i: %s', tag, 46, 1, '{"type":"remote-outbound-rtp","kind":"' + kind + '","packetsSent":350,"timestamp":16010}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(10, '%s: %i-%i: %s', tag, 47, 0, '{"type":"inbound-rtp","kind":"' + kind + '","bytesReceived":64042,"packetsReceived":400,"timestamp":17000}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(11, '%s: %i-%i: %s', tag, 48, 0, '{"type":"inbound-rtp","kind":"' + kind + '","packetsReceived":405,"timestamp":17990,"packetsLost":45,"codecId":"123456"}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(12, '%s: %i-%i: %s', tag, 48, 1, '{"type":"remote-outbound-rtp","kind":"' + kind + '","packetsSent":450,"timestamp":17990}') + }) + + test('partial stats', () => { + const tag = 'PeerConnectionAnalyzer: ' + kind + ': ' + + peerConnectionAnalyzer._logRtcStats(tag, kind, 46, 4) + + expect(consoleDebugMock).toHaveBeenCalledTimes(5) + expect(consoleDebugMock).toHaveBeenNthCalledWith(1, '%s: %i-%i: %s', tag, 46, 0, '{"type":"inbound-rtp","kind":"' + kind + '","packetsReceived":315,"timestamp":16010,"packetsLost":35}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(2, '%s: %i-%i: %s', tag, 46, 1, '{"type":"remote-outbound-rtp","kind":"' + kind + '","packetsSent":350,"timestamp":16010}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(3, '%s: %i-%i: %s', tag, 47, 0, '{"type":"inbound-rtp","kind":"' + kind + '","bytesReceived":64042,"packetsReceived":400,"timestamp":17000}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(4, '%s: %i-%i: %s', tag, 48, 0, '{"type":"inbound-rtp","kind":"' + kind + '","packetsReceived":405,"timestamp":17990,"packetsLost":45,"codecId":"123456"}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(5, '%s: %i-%i: %s', tag, 48, 1, '{"type":"remote-outbound-rtp","kind":"' + kind + '","packetsSent":450,"timestamp":17990}') + }) }) }) })