diff --git a/src/utils/webrtc/analyzers/ParticipantAnalyzer.js b/src/utils/webrtc/analyzers/ParticipantAnalyzer.js index 87ee26aec8e..4d23463a828 100644 --- a/src/utils/webrtc/analyzers/ParticipantAnalyzer.js +++ b/src/utils/webrtc/analyzers/ParticipantAnalyzer.js @@ -3,7 +3,11 @@ * SPDX-License-Identifier: AGPL-3.0-or-later */ -import { PEER_DIRECTION, PeerConnectionAnalyzer } from './PeerConnectionAnalyzer.js' +import { + PEER_DIRECTION, + PEER_TYPE, + PeerConnectionAnalyzer +} from './PeerConnectionAnalyzer.js' import EmitterMixin from '../../EmitterMixin.js' /** @@ -201,7 +205,7 @@ ParticipantAnalyzer.prototype = { _startListeningToScreenChanges() { if (this._localMediaModel) { - this._senderScreenPeerConnectionAnalyzer.setPeerConnection(this._screenPeer.pc, PEER_DIRECTION.SENDER) + this._senderScreenPeerConnectionAnalyzer.setPeerConnection(this._screenPeer.pc, PEER_DIRECTION.SENDER, PEER_TYPE.SCREEN) this._senderScreenPeerConnectionAnalyzer.on('change:connectionQualityVideo', this._handleConnectionQualityScreenChangeBound) @@ -210,7 +214,7 @@ ParticipantAnalyzer.prototype = { } if (this._callParticipantModel) { - this._receiverScreenPeerConnectionAnalyzer.setPeerConnection(this._screenPeer.pc, PEER_DIRECTION.RECEIVER) + this._receiverScreenPeerConnectionAnalyzer.setPeerConnection(this._screenPeer.pc, PEER_DIRECTION.RECEIVER, PEER_TYPE.SCREEN) this._receiverScreenPeerConnectionAnalyzer.on('change:connectionQualityVideo', this._handleConnectionQualityScreenChangeBound) diff --git a/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.js b/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.js index d0695a5d55b..47e9cf02302 100644 --- a/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.js +++ b/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.js @@ -20,6 +20,11 @@ const PEER_DIRECTION = { RECEIVER: 1, } +const PEER_TYPE = { + VIDEO: 0, + SCREEN: 1, +} + /** * Analyzer for the quality of the connection of an RTCPeerConnection. * @@ -56,6 +61,11 @@ const PEER_DIRECTION = { function PeerConnectionAnalyzer() { this._superEmitterMixin() + this._rtcStats = { + audio: [], + video: [], + } + this._packets = { audio: new AverageStatValue(5, STAT_VALUE_TYPE.CUMULATIVE), video: new AverageStatValue(5, STAT_VALUE_TYPE.CUMULATIVE), @@ -114,6 +124,7 @@ function PeerConnectionAnalyzer() { this._peerConnection = null this._peerDirection = null + this._peerType = null this._getStatsInterval = null @@ -154,7 +165,7 @@ PeerConnectionAnalyzer.prototype = { this._trigger('change:connectionQualityVideo', [connectionQualityVideo]) }, - setPeerConnection(peerConnection, peerDirection = null) { + setPeerConnection(peerConnection, peerDirection = null, peerType = PEER_TYPE.VIDEO) { if (this._peerConnection) { this._peerConnection.removeEventListener('iceconnectionstatechange', this._handleIceConnectionStateChangedBound) this._peerConnection.removeEventListener('connectionstatechange', this._handleConnectionStateChangedBound) @@ -163,6 +174,7 @@ PeerConnectionAnalyzer.prototype = { this._peerConnection = peerConnection this._peerDirection = peerDirection + this._peerType = peerType this._setConnectionQualityAudio(CONNECTION_QUALITY.UNKNOWN) this._setConnectionQualityVideo(CONNECTION_QUALITY.UNKNOWN) @@ -297,6 +309,17 @@ PeerConnectionAnalyzer.prototype = { }, _processSenderStats(stats) { + // Although the last five stats are analyzed a few more RTC stats are + // kept to provide an extended context in the logs. + const NUMBER_OF_RTC_STATS_TO_KEEP = 7 + + for (const kind of ['audio', 'video']) { + if (this._rtcStats[kind].length === NUMBER_OF_RTC_STATS_TO_KEEP) { + this._rtcStats[kind].shift() + } + this._rtcStats[kind].push([]) + } + // Packets are calculated as "packetsReceived + packetsLost" or as // "packetsSent" depending on the browser (see below). const packets = { @@ -353,6 +376,8 @@ PeerConnectionAnalyzer.prototype = { } if (stat.type === 'outbound-rtp') { + this._rtcStats[stat.kind][this._rtcStats[stat.kind].length - 1].push(stat) + if ('packetsSent' in stat && 'kind' in stat) { packetsSent[stat.kind] = (packetsSent[stat.kind] === -1) ? stat.packetsSent : packetsSent[stat.kind] + stat.packetsSent @@ -361,6 +386,8 @@ PeerConnectionAnalyzer.prototype = { } } } else if (stat.type === 'remote-inbound-rtp') { + this._rtcStats[stat.kind][this._rtcStats[stat.kind].length - 1].push(stat) + if ('packetsReceived' in stat && 'kind' in stat) { packetsReceived[stat.kind] = (packetsReceived[stat.kind] === -1) ? stat.packetsReceived : packetsReceived[stat.kind] + stat.packetsReceived @@ -506,11 +533,10 @@ PeerConnectionAnalyzer.prototype = { this._stageStats(kind, packets, packetsLost, timestamp, roundTripTime) - // If the packets have changed now it is assumed that the previous stats - // were stalled. - if (packets > 0) { - this._distributeStagedStats(kind) - } + // Distributing the stats has no effect if the stats were not stalled + // (that is, if the values are still unchanged, so it is probably an + // actual connection problem rather than a stalled report). + this._distributeStagedStats(kind) while (this._stagedPackets[kind].length > 0) { const stagedPackets = this._stagedPackets[kind].shift() @@ -550,6 +576,12 @@ PeerConnectionAnalyzer.prototype = { let packetsLostTotal = 0 let timestampsTotal = 0 + // If the last timestamp is still stalled there is nothing to + // distribute. + if (this._stagedTimestamps[kind][this._stagedTimestamps[kind].length - 1] === timestampsBase) { + return + } + // If the first timestamp stalled it is assumed that all of them // stalled and are thus evenly distributed based on the new timestamp. if (this._stagedTimestamps[kind][0] === timestampsBase) { @@ -719,8 +751,17 @@ PeerConnectionAnalyzer.prototype = { return CONNECTION_QUALITY.GOOD }, + _getLogTag(kind) { + let type = kind + if (this._peerType === PEER_TYPE.SCREEN) { + type += ' (screen)' + } + + return 'PeerConnectionAnalyzer: ' + type + ': ' + }, + _logStats(kind, message) { - const tag = 'PeerConnectionAnalyzer: ' + kind + ': ' + const tag = this._getLogTag(kind) if (message) { console.debug(tag + message) @@ -732,8 +773,25 @@ PeerConnectionAnalyzer.prototype = { console.debug(tag + 'Packets per second: ' + this._packetsPerSecond[kind].toString()) console.debug(tag + 'Round trip time: ' + this._roundTripTime[kind].toString()) console.debug(tag + 'Timestamps: ' + this._timestampsForLogs[kind].toString()) + + this._logRtcStats(kind) }, + _logRtcStats(kind) { + const tag = this._getLogTag(kind) + + for (const rtcStats of this._rtcStats[kind]) { + if (!rtcStats.length) { + console.debug(tag + 'no matching type') + continue + } + + for (const rtcStat of rtcStats) { + console.debug(tag + JSON.stringify(rtcStat)) + } + } + } + } EmitterMixin.apply(PeerConnectionAnalyzer.prototype) @@ -741,5 +799,6 @@ EmitterMixin.apply(PeerConnectionAnalyzer.prototype) export { CONNECTION_QUALITY, PEER_DIRECTION, + PEER_TYPE, PeerConnectionAnalyzer, } diff --git a/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.spec.js b/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.spec.js index d69844eaee8..2ebc4e298a5 100644 --- a/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.spec.js +++ b/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.spec.js @@ -6,6 +6,7 @@ import { CONNECTION_QUALITY, PEER_DIRECTION, + PEER_TYPE, PeerConnectionAnalyzer, } from './PeerConnectionAnalyzer.js' @@ -121,11 +122,25 @@ describe('PeerConnectionAnalyzer', () => { describe('analyze sender connection', () => { + let logStatsMock + + let expectLogStatsToHaveBeenCalled + beforeEach(() => { + logStatsMock = jest.spyOn(peerConnectionAnalyzer, '_logStats').mockImplementation(() => {}) + + expectLogStatsToHaveBeenCalled = false + peerConnection._setIceConnectionState('connected') peerConnection._setConnectionState('connected') }) + afterEach(() => { + if (!expectLogStatsToHaveBeenCalled) { + expect(logStatsMock).not.toHaveBeenCalled() + } + }) + test.each([ ['good quality', 'audio'], ['good quality', 'video'], @@ -573,6 +588,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(changeConnectionQualityAudioHandler).toHaveBeenCalledTimes(0) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(0) + expect(logStatsMock).toHaveBeenCalledTimes(0) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -593,6 +609,9 @@ describe('PeerConnectionAnalyzer', () => { expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(1) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledWith(peerConnectionAnalyzer, CONNECTION_QUALITY.VERY_BAD) } + expectLogStatsToHaveBeenCalled = true + expect(logStatsMock).toHaveBeenCalledTimes(1) + expect(logStatsMock).toHaveBeenCalledWith(kind, 'High packet lost ratio: 0.31') }) test.each([ @@ -640,6 +659,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(changeConnectionQualityAudioHandler).toHaveBeenCalledTimes(0) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(0) + expect(logStatsMock).toHaveBeenCalledTimes(0) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -660,6 +680,9 @@ describe('PeerConnectionAnalyzer', () => { expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(1) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledWith(peerConnectionAnalyzer, CONNECTION_QUALITY.VERY_BAD) } + expectLogStatsToHaveBeenCalled = true + expect(logStatsMock).toHaveBeenCalledTimes(1) + expect(logStatsMock).toHaveBeenCalledWith(kind, 'High packet lost ratio: 0.31') }) test.each([ @@ -707,6 +730,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(changeConnectionQualityAudioHandler).toHaveBeenCalledTimes(0) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(0) + expect(logStatsMock).toHaveBeenCalledTimes(0) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -727,11 +751,15 @@ describe('PeerConnectionAnalyzer', () => { expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(1) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledWith(peerConnectionAnalyzer, CONNECTION_QUALITY.VERY_BAD) } + expectLogStatsToHaveBeenCalled = true + expect(logStatsMock).toHaveBeenCalledTimes(2) + expect(logStatsMock).toHaveBeenNthCalledWith(1, kind, 'Low packets per second: 5.025140924550664') + expect(logStatsMock).toHaveBeenNthCalledWith(2, kind, 'High packet lost ratio: 0.4') }) test.each([ - ['good quality even with low packets if no packet loss, missing remote packet count', 'audio'], - ['good quality even with low packets if no packet loss, missing remote packet count', 'video'], + ['very bad quality with low packets and packet loss, missing remote packet count', 'audio'], + ['very bad quality with low packets and packet loss, missing remote packet count', 'video'], ])('%s, %s', async (name, kind) => { peerConnection.getStats .mockResolvedValueOnce(newRTCStatsReport([ @@ -774,6 +802,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(changeConnectionQualityAudioHandler).toHaveBeenCalledTimes(0) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(0) + expect(logStatsMock).toHaveBeenCalledTimes(0) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -794,6 +823,10 @@ describe('PeerConnectionAnalyzer', () => { expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(1) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledWith(peerConnectionAnalyzer, CONNECTION_QUALITY.VERY_BAD) } + expectLogStatsToHaveBeenCalled = true + expect(logStatsMock).toHaveBeenCalledTimes(2) + expect(logStatsMock).toHaveBeenNthCalledWith(1, kind, 'Low packets per second: 5.025140924550664') + expect(logStatsMock).toHaveBeenNthCalledWith(2, kind, 'High packet lost ratio: 0.4') }) test.each([ @@ -841,6 +874,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(changeConnectionQualityAudioHandler).toHaveBeenCalledTimes(0) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(0) + expect(logStatsMock).toHaveBeenCalledTimes(0) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -861,6 +895,9 @@ describe('PeerConnectionAnalyzer', () => { expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(1) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledWith(peerConnectionAnalyzer, CONNECTION_QUALITY.GOOD) } + expectLogStatsToHaveBeenCalled = true + expect(logStatsMock).toHaveBeenCalledTimes(1) + expect(logStatsMock).toHaveBeenCalledWith(kind, 'Low packets per second: 5.025140924550664') }) test.each([ @@ -908,6 +945,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(changeConnectionQualityAudioHandler).toHaveBeenCalledTimes(0) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(0) + expect(logStatsMock).toHaveBeenCalledTimes(0) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -928,6 +966,9 @@ describe('PeerConnectionAnalyzer', () => { expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(1) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledWith(peerConnectionAnalyzer, CONNECTION_QUALITY.GOOD) } + expectLogStatsToHaveBeenCalled = true + expect(logStatsMock).toHaveBeenCalledTimes(1) + expect(logStatsMock).toHaveBeenCalledWith(kind, 'Low packets per second: 5.025140924550664') }) test.each([ @@ -975,6 +1016,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(changeConnectionQualityAudioHandler).toHaveBeenCalledTimes(0) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(0) + expect(logStatsMock).toHaveBeenCalledTimes(0) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -995,6 +1037,9 @@ describe('PeerConnectionAnalyzer', () => { expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(1) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledWith(peerConnectionAnalyzer, CONNECTION_QUALITY.VERY_BAD) } + expectLogStatsToHaveBeenCalled = true + expect(logStatsMock).toHaveBeenCalledTimes(1) + expect(logStatsMock).toHaveBeenCalledWith(kind, 'High round trip time: 1.5133333333333334') }) test.each([ @@ -1042,6 +1087,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(changeConnectionQualityAudioHandler).toHaveBeenCalledTimes(0) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(0) + expect(logStatsMock).toHaveBeenCalledTimes(0) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -1062,6 +1108,9 @@ describe('PeerConnectionAnalyzer', () => { expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(1) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledWith(peerConnectionAnalyzer, CONNECTION_QUALITY.VERY_BAD) } + expectLogStatsToHaveBeenCalled = true + expect(logStatsMock).toHaveBeenCalledTimes(1) + expect(logStatsMock).toHaveBeenCalledWith(kind, 'High round trip time: 1.5133333333333334') }) test.each([ @@ -1109,6 +1158,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(changeConnectionQualityAudioHandler).toHaveBeenCalledTimes(0) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(0) + expect(logStatsMock).toHaveBeenCalledTimes(0) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -1129,6 +1179,9 @@ describe('PeerConnectionAnalyzer', () => { expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(1) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledWith(peerConnectionAnalyzer, CONNECTION_QUALITY.NO_TRANSMITTED_DATA) } + expectLogStatsToHaveBeenCalled = true + expect(logStatsMock).toHaveBeenCalledTimes(1) + expect(logStatsMock).toHaveBeenCalledWith(kind, 'No transmitted data, packet lost ratio: 1') }) test.each([ @@ -1176,6 +1229,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(changeConnectionQualityAudioHandler).toHaveBeenCalledTimes(0) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(0) + expect(logStatsMock).toHaveBeenCalledTimes(0) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -1196,6 +1250,9 @@ describe('PeerConnectionAnalyzer', () => { expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(1) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledWith(peerConnectionAnalyzer, CONNECTION_QUALITY.NO_TRANSMITTED_DATA) } + expectLogStatsToHaveBeenCalled = true + expect(logStatsMock).toHaveBeenCalledTimes(1) + expect(logStatsMock).toHaveBeenCalledWith(kind, 'No transmitted data, packet lost ratio: 1') }) test.each([ @@ -1251,6 +1308,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(changeConnectionQualityAudioHandler).toHaveBeenCalledTimes(0) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(0) + expect(logStatsMock).toHaveBeenCalledTimes(0) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -1271,6 +1329,9 @@ describe('PeerConnectionAnalyzer', () => { expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(1) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledWith(peerConnectionAnalyzer, CONNECTION_QUALITY.NO_TRANSMITTED_DATA) } + expectLogStatsToHaveBeenCalled = true + expect(logStatsMock).toHaveBeenCalledTimes(1) + expect(logStatsMock).toHaveBeenCalledWith(kind, 'No transmitted data, packet lost ratio: 1.35') }) test.each([ @@ -1326,6 +1387,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(changeConnectionQualityAudioHandler).toHaveBeenCalledTimes(0) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(0) + expect(logStatsMock).toHaveBeenCalledTimes(0) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -1346,6 +1408,9 @@ describe('PeerConnectionAnalyzer', () => { expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(1) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledWith(peerConnectionAnalyzer, CONNECTION_QUALITY.NO_TRANSMITTED_DATA) } + expectLogStatsToHaveBeenCalled = true + expect(logStatsMock).toHaveBeenCalledTimes(1) + expect(logStatsMock).toHaveBeenCalledWith(kind, 'No transmitted data, packet lost ratio: 1.35') }) test.each([ @@ -1917,6 +1982,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(changeConnectionQualityAudioHandler).toHaveBeenCalledTimes(0) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(0) + expect(logStatsMock).toHaveBeenCalledTimes(0) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -1937,6 +2003,9 @@ describe('PeerConnectionAnalyzer', () => { expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(1) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledWith(peerConnectionAnalyzer, CONNECTION_QUALITY.VERY_BAD) } + expectLogStatsToHaveBeenCalled = true + expect(logStatsMock).toHaveBeenCalledTimes(1) + expect(logStatsMock).toHaveBeenCalledWith(kind, 'High packet lost ratio: 0.825') }) test.each([ @@ -1994,6 +2063,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(changeConnectionQualityAudioHandler).toHaveBeenCalledTimes(0) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(0) + expect(logStatsMock).toHaveBeenCalledTimes(0) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -2014,6 +2084,9 @@ describe('PeerConnectionAnalyzer', () => { expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(1) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledWith(peerConnectionAnalyzer, CONNECTION_QUALITY.VERY_BAD) } + expectLogStatsToHaveBeenCalled = true + expect(logStatsMock).toHaveBeenCalledTimes(1) + expect(logStatsMock).toHaveBeenCalledWith(kind, 'High packet lost ratio: 0.825') }) test.each([ @@ -2808,6 +2881,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityAudio()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.BAD) } + expect(logStatsMock).toHaveBeenCalledTimes(0) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -2822,6 +2896,9 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityAudio()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.VERY_BAD) } + expectLogStatsToHaveBeenCalled = true + expect(logStatsMock).toHaveBeenCalledTimes(1) + expect(logStatsMock).toHaveBeenCalledWith(kind, 'High packet lost ratio: 0.32') }) test.each([ @@ -2885,6 +2962,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(changeConnectionQualityAudioHandler).toHaveBeenCalledTimes(0) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(0) + expect(logStatsMock).toHaveBeenCalledTimes(0) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -2899,6 +2977,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityAudio()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.GOOD) } + expect(logStatsMock).toHaveBeenCalledTimes(0) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -2913,6 +2992,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityAudio()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.GOOD) } + expect(logStatsMock).toHaveBeenCalledTimes(0) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -2927,6 +3007,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityAudio()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.MEDIUM) } + expect(logStatsMock).toHaveBeenCalledTimes(0) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -2941,6 +3022,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityAudio()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.BAD) } + expect(logStatsMock).toHaveBeenCalledTimes(0) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -2955,6 +3037,9 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityAudio()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.VERY_BAD) } + expectLogStatsToHaveBeenCalled = true + expect(logStatsMock).toHaveBeenCalledTimes(1) + expect(logStatsMock).toHaveBeenCalledWith(kind, 'High packet lost ratio: 0.32') }) test.each([ @@ -3018,6 +3103,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(changeConnectionQualityAudioHandler).toHaveBeenCalledTimes(0) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(0) + expect(logStatsMock).toHaveBeenCalledTimes(0) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -3032,6 +3118,9 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityAudio()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.VERY_BAD) } + expectLogStatsToHaveBeenCalled = true + expect(logStatsMock).toHaveBeenCalledTimes(1) + expect(logStatsMock).toHaveBeenCalledWith(kind, 'High packet lost ratio: 0.31') jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -3046,6 +3135,8 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityAudio()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.VERY_BAD) } + expect(logStatsMock).toHaveBeenCalledTimes(2) + expect(logStatsMock).toHaveBeenNthCalledWith(2, kind, 'High packet lost ratio: 0.325') jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -3060,6 +3151,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityAudio()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.BAD) } + expect(logStatsMock).toHaveBeenCalledTimes(2) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -3074,6 +3166,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityAudio()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.MEDIUM) } + expect(logStatsMock).toHaveBeenCalledTimes(2) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -3088,6 +3181,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityAudio()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.GOOD) } + expect(logStatsMock).toHaveBeenCalledTimes(2) }) test.each([ @@ -3151,6 +3245,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(changeConnectionQualityAudioHandler).toHaveBeenCalledTimes(0) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(0) + expect(logStatsMock).toHaveBeenCalledTimes(0) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -3165,6 +3260,9 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityAudio()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.VERY_BAD) } + expectLogStatsToHaveBeenCalled = true + expect(logStatsMock).toHaveBeenCalledTimes(1) + expect(logStatsMock).toHaveBeenCalledWith(kind, 'High packet lost ratio: 0.31') jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -3193,6 +3291,8 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityAudio()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.BAD) } + expect(logStatsMock).toHaveBeenCalledTimes(2) + expect(logStatsMock).toHaveBeenNthCalledWith(2, kind, 'High packet lost ratio: 0.325') jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -3207,6 +3307,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityAudio()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.MEDIUM) } + expect(logStatsMock).toHaveBeenCalledTimes(2) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -3221,6 +3322,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityAudio()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.GOOD) } + expect(logStatsMock).toHaveBeenCalledTimes(2) }) test('good audio quality, very bad video quality', async () => { @@ -3277,6 +3379,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(changeConnectionQualityAudioHandler).toHaveBeenCalledTimes(0) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(0) + expect(logStatsMock).toHaveBeenCalledTimes(0) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -3290,6 +3393,9 @@ describe('PeerConnectionAnalyzer', () => { expect(changeConnectionQualityAudioHandler).toHaveBeenCalledWith(peerConnectionAnalyzer, CONNECTION_QUALITY.GOOD) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(1) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledWith(peerConnectionAnalyzer, CONNECTION_QUALITY.VERY_BAD) + expectLogStatsToHaveBeenCalled = true + expect(logStatsMock).toHaveBeenCalledTimes(1) + expect(logStatsMock).toHaveBeenCalledWith('video', 'High packet lost ratio: 0.31') }) test('very bad audio quality, good video quality', async () => { @@ -3346,6 +3452,7 @@ describe('PeerConnectionAnalyzer', () => { expect(peerConnectionAnalyzer.getConnectionQualityVideo()).toBe(CONNECTION_QUALITY.UNKNOWN) expect(changeConnectionQualityAudioHandler).toHaveBeenCalledTimes(0) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(0) + expect(logStatsMock).toHaveBeenCalledTimes(0) jest.advanceTimersByTime(1000) // Force the promises returning the stats to be executed. @@ -3359,6 +3466,451 @@ describe('PeerConnectionAnalyzer', () => { expect(changeConnectionQualityAudioHandler).toHaveBeenCalledWith(peerConnectionAnalyzer, CONNECTION_QUALITY.VERY_BAD) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledTimes(1) expect(changeConnectionQualityVideoHandler).toHaveBeenCalledWith(peerConnectionAnalyzer, CONNECTION_QUALITY.GOOD) + expectLogStatsToHaveBeenCalled = true + expect(logStatsMock).toHaveBeenCalledTimes(1) + expect(logStatsMock).toHaveBeenCalledWith('audio', 'High packet lost ratio: 0.31') + }) + }) + + describe('add stats', () => { + test.each([ + ['initial stats', 'audio'], + ['initial stats', 'video'], + ])('%s, %s', (name, kind) => { + peerConnectionAnalyzer._addStats(kind, 150, 40, 10000, 0.2) + + expect(peerConnectionAnalyzer._packets[kind]._relativeValues).toEqual([0]) + expect(peerConnectionAnalyzer._packetsLost[kind]._relativeValues).toEqual([0]) + expect(peerConnectionAnalyzer._packetsLostRatio[kind]._relativeValues).toEqual([1.5]) + expect(peerConnectionAnalyzer._timestamps[kind]._relativeValues).toEqual([0]) + expect(peerConnectionAnalyzer._timestampsForLogs[kind]._relativeValues).toEqual([0]) + expect(peerConnectionAnalyzer._packetsPerSecond[kind]._relativeValues).toEqual([NaN]) + expect(peerConnectionAnalyzer._roundTripTime[kind]._relativeValues).toEqual([0.2]) + }) + + test.each([ + ['packet count not repeated', 'audio'], + ['packet count not repeated', 'video'], + ])('%s, %s', (name, kind) => { + peerConnectionAnalyzer._addStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._addStats(kind, 200, 50, 11250, 0.3) + + expect(peerConnectionAnalyzer._packets[kind]._relativeValues).toEqual([0, 50]) + expect(peerConnectionAnalyzer._packetsLost[kind]._relativeValues).toEqual([0, 10]) + expect(peerConnectionAnalyzer._packetsLostRatio[kind]._relativeValues).toEqual([1.5, 0.2]) + expect(peerConnectionAnalyzer._timestamps[kind]._relativeValues).toEqual([0, 1250]) + expect(peerConnectionAnalyzer._timestampsForLogs[kind]._relativeValues).toEqual([0, 1250]) + expect(peerConnectionAnalyzer._packetsPerSecond[kind]._relativeValues).toEqual([NaN, 40]) + expect(peerConnectionAnalyzer._roundTripTime[kind]._relativeValues).toEqual([0.2, 0.3]) + }) + + test.each([ + ['packet count repeated one time', 'audio'], + ['packet count repeated one time', 'video'], + ])('%s, %s', (name, kind) => { + peerConnectionAnalyzer._addStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._addStats(kind, 150, 40, 10000, 0.2) + + expect(peerConnectionAnalyzer._packets[kind]._relativeValues).toEqual([0]) + expect(peerConnectionAnalyzer._packetsLost[kind]._relativeValues).toEqual([0]) + expect(peerConnectionAnalyzer._packetsLostRatio[kind]._relativeValues).toEqual([1.5]) + expect(peerConnectionAnalyzer._timestamps[kind]._relativeValues).toEqual([0]) + expect(peerConnectionAnalyzer._timestampsForLogs[kind]._relativeValues).toEqual([0]) + expect(peerConnectionAnalyzer._packetsPerSecond[kind]._relativeValues).toEqual([NaN]) + expect(peerConnectionAnalyzer._roundTripTime[kind]._relativeValues).toEqual([0.2]) + + expect(peerConnectionAnalyzer._stagedPackets[kind]).toEqual([150]) + expect(peerConnectionAnalyzer._stagedPacketsLost[kind]).toEqual([40]) + expect(peerConnectionAnalyzer._stagedTimestamps[kind]).toEqual([10000]) + expect(peerConnectionAnalyzer._stagedRoundTripTime[kind]).toEqual([0.2]) + }) + + test.each([ + ['packet count repeated one time then changed', 'audio'], + ['packet count repeated one time then changed', 'video'], + ])('%s, %s', (name, kind) => { + peerConnectionAnalyzer._addStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._addStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._addStats(kind, 250, 60, 12500, 0.3) + + expect(peerConnectionAnalyzer._packets[kind]._relativeValues).toEqual([0, 50, 50]) + expect(peerConnectionAnalyzer._packetsLost[kind]._relativeValues).toEqual([0, 10, 10]) + expect(peerConnectionAnalyzer._packetsLostRatio[kind]._relativeValues).toEqual([1.5, 0.2, 0.2]) + expect(peerConnectionAnalyzer._timestamps[kind]._relativeValues).toEqual([1250, 1250]) + expect(peerConnectionAnalyzer._timestampsForLogs[kind]._relativeValues).toEqual([0, 1250, 1250]) + expect(peerConnectionAnalyzer._packetsPerSecond[kind]._relativeValues).toEqual([NaN, 40, 40]) + expect(peerConnectionAnalyzer._roundTripTime[kind]._relativeValues).toEqual([0.2, 0.2, 0.3]) + + expect(peerConnectionAnalyzer._stagedPackets[kind]).toEqual([]) + expect(peerConnectionAnalyzer._stagedPacketsLost[kind]).toEqual([]) + expect(peerConnectionAnalyzer._stagedTimestamps[kind]).toEqual([]) + expect(peerConnectionAnalyzer._stagedRoundTripTime[kind]).toEqual([]) + }) + + test.each([ + ['packet count repeated two times', 'audio'], + ['packet count repeated two times', 'video'], + ])('%s, %s', (name, kind) => { + peerConnectionAnalyzer._addStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._addStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._addStats(kind, 150, 40, 10000, 0.2) + + expect(peerConnectionAnalyzer._packets[kind]._relativeValues).toEqual([0, 0, 0]) + expect(peerConnectionAnalyzer._packetsLost[kind]._relativeValues).toEqual([0, 0, 0]) + expect(peerConnectionAnalyzer._packetsLostRatio[kind]._relativeValues).toEqual([1.5, 1.5, 1.5]) + expect(peerConnectionAnalyzer._timestamps[kind]._relativeValues).toEqual([0, 0]) + expect(peerConnectionAnalyzer._timestampsForLogs[kind]._relativeValues).toEqual([0, 0, 0]) + expect(peerConnectionAnalyzer._packetsPerSecond[kind]._relativeValues).toEqual([NaN, NaN, NaN]) + expect(peerConnectionAnalyzer._roundTripTime[kind]._relativeValues).toEqual([0.2, 0.2, 0.2]) + + expect(peerConnectionAnalyzer._stagedPackets[kind]).toEqual([]) + expect(peerConnectionAnalyzer._stagedPacketsLost[kind]).toEqual([]) + expect(peerConnectionAnalyzer._stagedTimestamps[kind]).toEqual([]) + expect(peerConnectionAnalyzer._stagedRoundTripTime[kind]).toEqual([]) + }) + + test.each([ + ['packet count repeated two times then changed', 'audio'], + ['packet count repeated two times then changed', 'video'], + ])('%s, %s', (name, kind) => { + peerConnectionAnalyzer._addStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._addStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._addStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._addStats(kind, 300, 70, 13750, 0.3) + + expect(peerConnectionAnalyzer._packets[kind]._relativeValues).toEqual([0, 0, 0, 150]) + expect(peerConnectionAnalyzer._packetsLost[kind]._relativeValues).toEqual([0, 0, 0, 30]) + expect(peerConnectionAnalyzer._packetsLostRatio[kind]._relativeValues).toEqual([1.5, 1.5, 1.5, 0.2]) + expect(peerConnectionAnalyzer._timestamps[kind]._relativeValues).toEqual([0, 3750]) + expect(peerConnectionAnalyzer._timestampsForLogs[kind]._relativeValues).toEqual([0, 0, 0, 3750]) + expect(peerConnectionAnalyzer._packetsPerSecond[kind]._relativeValues).toEqual([NaN, NaN, NaN, 40]) + expect(peerConnectionAnalyzer._roundTripTime[kind]._relativeValues).toEqual([0.2, 0.2, 0.2, 0.3]) + + expect(peerConnectionAnalyzer._stagedPackets[kind]).toEqual([]) + expect(peerConnectionAnalyzer._stagedPacketsLost[kind]).toEqual([]) + expect(peerConnectionAnalyzer._stagedTimestamps[kind]).toEqual([]) + expect(peerConnectionAnalyzer._stagedRoundTripTime[kind]).toEqual([]) + }) + + describe('distribute staged stats', () => { + + const expectRelativeStagedStats = (kind, index, expectedPackets, expectedPacketsLost, expectedTimestamps, expectedRoundTripTime) => { + expect(peerConnectionAnalyzer._stagedPackets[kind][index]).toBe(expectedPackets) + expect(peerConnectionAnalyzer._stagedPacketsLost[kind][index]).toBe(expectedPacketsLost) + expect(peerConnectionAnalyzer._stagedTimestamps[kind][index]).toBe(expectedTimestamps) + expect(peerConnectionAnalyzer._stagedRoundTripTime[kind][index]).toBe(expectedRoundTripTime) + } + + test.each([ + ['two sets of different values with repeated timestamps', 'audio'], + ['two sets of different values with repeated timestamps', 'video'], + ])('%s, %s', (name, kind) => { + peerConnectionAnalyzer._commitStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 250, 60, 12500, 0.3) + + peerConnectionAnalyzer._distributeStagedStats(kind) + + expectRelativeStagedStats(kind, 0, 200, 50, 11250, 0.2) + expectRelativeStagedStats(kind, 1, 250, 60, 12500, 0.3) + }) + + test.each([ + ['two sets of different values without repeated timestamps', 'audio'], + ['two sets of different values without repeated timestamps', 'video'], + ])('%s, %s', (name, kind) => { + peerConnectionAnalyzer._commitStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 11000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 250, 60, 14000, 0.3) + + peerConnectionAnalyzer._distributeStagedStats(kind) + + expectRelativeStagedStats(kind, 0, 175, 45, 11000, 0.2) + expectRelativeStagedStats(kind, 1, 250, 60, 14000, 0.3) + }) + + test.each([ + ['two sets of repeated values with repeated timestamps', 'audio'], + ['two sets of repeated values with repeated timestamps', 'video'], + ])('%s, %s', (name, kind) => { + peerConnectionAnalyzer._commitStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 12500, 0.2) + + peerConnectionAnalyzer._distributeStagedStats(kind) + + expectRelativeStagedStats(kind, 0, 150, 40, 11250, 0.2) + expectRelativeStagedStats(kind, 1, 150, 40, 12500, 0.2) + }) + + test.each([ + ['two sets of repeated values without repeated timestamps', 'audio'], + ['two sets of repeated values without repeated timestamps', 'video'], + ])('%s, %s', (name, kind) => { + peerConnectionAnalyzer._commitStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 11000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 14000, 0.2) + + peerConnectionAnalyzer._distributeStagedStats(kind) + + expectRelativeStagedStats(kind, 0, 150, 40, 11000, 0.2) + expectRelativeStagedStats(kind, 1, 150, 40, 14000, 0.2) + }) + + test.each([ + ['two sets of fully repeated values', 'audio'], + ['two sets of fully repeated values', 'video'], + ])('%s, %s', (name, kind) => { + peerConnectionAnalyzer._commitStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 10000, 0.2) + + peerConnectionAnalyzer._distributeStagedStats(kind) + + expectRelativeStagedStats(kind, 0, 150, 40, 10000, 0.2) + expectRelativeStagedStats(kind, 1, 150, 40, 10000, 0.2) + }) + + test.each([ + ['several sets of different values with repeated timestamps', 'audio'], + ['several sets of different values with repeated timestamps', 'video'], + ])('%s, %s', (name, kind) => { + peerConnectionAnalyzer._commitStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 10000, 0.3) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 10000, 0.4) + peerConnectionAnalyzer._stageStats(kind, 350, 80, 14000, 0.1) + + peerConnectionAnalyzer._distributeStagedStats(kind) + + expectRelativeStagedStats(kind, 0, 200, 50, 11000, 0.2) + expectRelativeStagedStats(kind, 1, 250, 60, 12000, 0.3) + expectRelativeStagedStats(kind, 2, 300, 70, 13000, 0.4) + expectRelativeStagedStats(kind, 3, 350, 80, 14000, 0.1) + }) + + test.each([ + ['several sets of different values without repeated timestamps', 'audio'], + ['several sets of different values without repeated timestamps', 'video'], + ])('%s, %s', (name, kind) => { + peerConnectionAnalyzer._commitStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 11000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 15000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 18000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 350, 80, 20000, 0.2) + + peerConnectionAnalyzer._distributeStagedStats(kind) + + expectRelativeStagedStats(kind, 0, 170, 44, 11000, 0.2) + expectRelativeStagedStats(kind, 1, 250, 60, 15000, 0.2) + expectRelativeStagedStats(kind, 2, 310, 72, 18000, 0.2) + expectRelativeStagedStats(kind, 3, 350, 80, 20000, 0.2) + }) + + test.each([ + ['several sets of repeated values with repeated timestamps', 'audio'], + ['several sets of repeated values with repeated timestamps', 'video'], + ])('%s, %s', (name, kind) => { + peerConnectionAnalyzer._commitStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 14000, 0.2) + + peerConnectionAnalyzer._distributeStagedStats(kind) + + expectRelativeStagedStats(kind, 0, 150, 40, 11000, 0.2) + expectRelativeStagedStats(kind, 1, 150, 40, 12000, 0.2) + expectRelativeStagedStats(kind, 2, 150, 40, 13000, 0.2) + expectRelativeStagedStats(kind, 3, 150, 40, 14000, 0.2) + }) + + test.each([ + ['several sets of repeated values without repeated timestamps', 'audio'], + ['several sets of repeated values without repeated timestamps', 'video'], + ])('%s, %s', (name, kind) => { + peerConnectionAnalyzer._commitStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 11000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 15000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 17500, 0.2) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 20000, 0.2) + + peerConnectionAnalyzer._distributeStagedStats(kind) + + expectRelativeStagedStats(kind, 0, 150, 40, 11000, 0.2) + expectRelativeStagedStats(kind, 1, 150, 40, 15000, 0.2) + expectRelativeStagedStats(kind, 2, 150, 40, 17500, 0.2) + expectRelativeStagedStats(kind, 3, 150, 40, 20000, 0.2) + }) + + test.each([ + ['several sets of fully repeated values', 'audio'], + ['several sets of fully repeated values', 'video'], + ])('%s, %s', (name, kind) => { + peerConnectionAnalyzer._commitStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._stageStats(kind, 150, 40, 10000, 0.2) + + peerConnectionAnalyzer._distributeStagedStats(kind) + + expectRelativeStagedStats(kind, 0, 150, 40, 10000, 0.2) + expectRelativeStagedStats(kind, 1, 150, 40, 10000, 0.2) + expectRelativeStagedStats(kind, 2, 150, 40, 10000, 0.2) + expectRelativeStagedStats(kind, 3, 150, 40, 10000, 0.2) + }) + }) + }) + + describe('log stats', () => { + + let consoleDebugMock + + beforeEach(() => { + consoleDebugMock = jest.spyOn(console, 'debug') + }) + + test.each([ + ['video peer', 'audio'], + ['video peer', 'video'], + ])('%s, %s', (name, kind) => { + const logRtcStatsMock = jest.spyOn(peerConnectionAnalyzer, '_logRtcStats').mockImplementation(() => {}) + + peerConnectionAnalyzer.setPeerConnection(peerConnection, PEER_DIRECTION.SENDER) + + peerConnectionAnalyzer._addStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._addStats(kind, 200, 50, 11250, 0.3) + peerConnectionAnalyzer._addStats(kind, 260, 56, 12250, 0.4) + + peerConnectionAnalyzer._logStats(kind, 'Message to log') + + const tag = 'PeerConnectionAnalyzer: ' + kind + + expect(consoleDebugMock).toHaveBeenCalledTimes(7) + expect(consoleDebugMock).toHaveBeenNthCalledWith(1, tag + ': Message to log') + expect(consoleDebugMock).toHaveBeenNthCalledWith(2, tag + ': Packets: [0, 50, 60]') + expect(consoleDebugMock).toHaveBeenNthCalledWith(3, tag + ': Packets lost: [0, 10, 6]') + expect(consoleDebugMock).toHaveBeenNthCalledWith(4, tag + ': Packets lost ratio: [1.5, 0.2, 0.1]') + expect(consoleDebugMock).toHaveBeenNthCalledWith(5, tag + ': Packets per second: [NaN, 40, 60]') + expect(consoleDebugMock).toHaveBeenNthCalledWith(6, tag + ': Round trip time: [0.2, 0.3, 0.4]') + expect(consoleDebugMock).toHaveBeenNthCalledWith(7, tag + ': Timestamps: [0, 1250, 1000]') + expect(logRtcStatsMock).toHaveBeenCalledTimes(1) + expect(logRtcStatsMock).toHaveBeenCalledWith(kind) + }) + + test.each([ + ['screen peer', 'audio'], + ['screen peer', 'video'], + ])('%s, %s', (name, kind) => { + const logRtcStatsMock = jest.spyOn(peerConnectionAnalyzer, '_logRtcStats').mockImplementation(() => {}) + + peerConnectionAnalyzer.setPeerConnection(peerConnection, PEER_DIRECTION.SENDER, PEER_TYPE.SCREEN) + + peerConnectionAnalyzer._addStats(kind, 150, 40, 10000, 0.2) + peerConnectionAnalyzer._addStats(kind, 200, 50, 11250, 0.3) + peerConnectionAnalyzer._addStats(kind, 260, 56, 12250, 0.4) + + peerConnectionAnalyzer._logStats(kind, 'Message to log') + + const tag = 'PeerConnectionAnalyzer: ' + kind + ' (screen)' + + expect(consoleDebugMock).toHaveBeenCalledTimes(7) + expect(consoleDebugMock).toHaveBeenNthCalledWith(1, tag + ': Message to log') + expect(consoleDebugMock).toHaveBeenNthCalledWith(2, tag + ': Packets: [0, 50, 60]') + expect(consoleDebugMock).toHaveBeenNthCalledWith(3, tag + ': Packets lost: [0, 10, 6]') + expect(consoleDebugMock).toHaveBeenNthCalledWith(4, tag + ': Packets lost ratio: [1.5, 0.2, 0.1]') + expect(consoleDebugMock).toHaveBeenNthCalledWith(5, tag + ': Packets per second: [NaN, 40, 60]') + expect(consoleDebugMock).toHaveBeenNthCalledWith(6, tag + ': Round trip time: [0.2, 0.3, 0.4]') + expect(consoleDebugMock).toHaveBeenNthCalledWith(7, tag + ': Timestamps: [0, 1250, 1000]') + expect(logRtcStatsMock).toHaveBeenCalledTimes(1) + expect(logRtcStatsMock).toHaveBeenCalledWith(kind) + }) + + describe('log RTC stats', () => { + + beforeEach(() => { + peerConnection._setIceConnectionState('connected') + peerConnection._setConnectionState('connected') + }) + + test.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) + + jest.advanceTimersByTime(9000) + // Force the promises returning the stats to be executed. + await null + + peerConnectionAnalyzer._logRtcStats(kind) + + const tag = 'PeerConnectionAnalyzer: ' + kind + + expect(consoleDebugMock).toHaveBeenCalledTimes(15) + expect(consoleDebugMock).toHaveBeenNthCalledWith(1, tag + ': {"type":"outbound-rtp","kind":"' + kind + '","id":"67890","packetsSent":150,"timestamp":11950,"rid":"h"}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(2, tag + ': {"type":"outbound-rtp","kind":"' + kind + '","id":"abcde","packetsSent":80,"timestamp":11950,"rid":"m"}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(3, tag + ': {"type":"remote-inbound-rtp","kind":"' + kind + '","localId":"67890","packetsReceived":135,"timestamp":11950,"packetsLost":15,"roundTripTime":0.1}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(4, tag + ': {"type":"remote-inbound-rtp","kind":"' + kind + '","localId":"abcde","packetsReceived":72,"timestamp":11950,"packetsLost":8,"roundTripTime":0.1}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(5, tag + ': {"type":"outbound-rtp","kind":"' + kind + '","packetsSent":200,"timestamp":13020}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(6, tag + ': {"type":"remote-inbound-rtp","kind":"' + kind + '","packetsReceived":180,"timestamp":13020,"packetsLost":20,"roundTripTime":0.15,"jitter":0.007}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(7, tag + ': no matching type') + expect(consoleDebugMock).toHaveBeenNthCalledWith(8, tag + ': {"type":"outbound-rtp","kind":"' + kind + '","packetsSent":300,"timestamp":14985}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(9, tag + ': {"type":"remote-inbound-rtp","kind":"' + kind + '","packetsReceived":270,"timestamp":14985,"packetsLost":30,"roundTripTime":0.3}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(10, tag + ': {"type":"outbound-rtp","kind":"' + kind + '","packetsSent":350,"timestamp":16010}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(11, tag + ': {"type":"remote-inbound-rtp","kind":"' + kind + '","packetsReceived":315,"timestamp":16010,"packetsLost":35,"roundTripTime":0.25}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(12, tag + ': {"type":"outbound-rtp","kind":"' + kind + '","bytesSent":64042,"packetsSent":400,"timestamp":17000}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(13, tag + ': {"type":"remote-inbound-rtp","kind":"' + kind + '","packetsReceived":360,"timestamp":17000,"packetsLost":40,"roundTripTime":0.15}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(14, tag + ': {"type":"outbound-rtp","kind":"' + kind + '","packetsSent":450,"timestamp":17990,"codecId":"123456"}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(15, tag + ': {"type":"remote-inbound-rtp","kind":"' + kind + '","packetsReceived":405,"timestamp":17990,"packetsLost":45,"roundTripTime":0.2}') + }) }) }) })