From 549c4ac8db0abe000595fb907606b852447ce9ad Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Daniel=20Calvi=C3=B1o=20S=C3=A1nchez?= Date: Sun, 16 Feb 2025 12:59:09 +0100 Subject: [PATCH 1/4] test: Fix wrong test name MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Signed-off-by: Daniel Calviño Sánchez --- src/utils/webrtc/analyzers/PeerConnectionAnalyzer.spec.js | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.spec.js b/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.spec.js index 5ec0efe1972..ca299ac7948 100644 --- a/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.spec.js +++ b/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.spec.js @@ -730,8 +730,8 @@ describe('PeerConnectionAnalyzer', () => { }) 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([ From cc91ac2389b682f48f4ee3fee85d80d30a887f28 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Daniel=20Calvi=C3=B1o=20S=C3=A1nchez?= Date: Sun, 16 Feb 2025 13:17:16 +0100 Subject: [PATCH 2/4] test: Verify information logged when analyzing the connection MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Signed-off-by: Daniel Calviño Sánchez --- .../analyzers/PeerConnectionAnalyzer.spec.js | 109 ++++++++++++++++++ 1 file changed, 109 insertions(+) diff --git a/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.spec.js b/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.spec.js index ca299ac7948..7504ba348d4 100644 --- a/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.spec.js +++ b/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.spec.js @@ -121,11 +121,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 +587,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 +608,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 +658,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 +679,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 +729,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,6 +750,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([ @@ -774,6 +801,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 +822,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 +873,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 +894,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 +944,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 +965,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 +1015,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 +1036,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 +1086,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 +1107,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 +1157,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 +1178,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 +1228,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 +1249,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 +1307,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 +1328,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 +1386,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 +1407,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 +1981,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 +2002,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 +2062,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 +2083,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 +2880,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 +2895,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 +2961,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 +2976,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 +2991,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 +3006,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 +3021,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 +3036,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 +3102,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 +3117,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 +3134,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 +3150,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 +3165,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 +3180,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 +3244,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 +3259,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 +3290,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 +3306,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 +3321,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 +3378,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 +3392,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 +3451,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 +3465,9 @@ 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') }) }) From ce4a16b551536a0e15dc47e2015ca69c45dfa58b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Daniel=20Calvi=C3=B1o=20S=C3=A1nchez?= Date: Sun, 16 Feb 2025 14:56:16 +0100 Subject: [PATCH 3/4] fix: Add peer type to logged stats MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Otherwise it was not possible to know if the logged stats belonged to the video or screen peer. Signed-off-by: Daniel Calviño Sánchez --- .../webrtc/analyzers/ParticipantAnalyzer.js | 10 +++- .../analyzers/PeerConnectionAnalyzer.js | 21 ++++++- .../analyzers/PeerConnectionAnalyzer.spec.js | 58 +++++++++++++++++++ 3 files changed, 84 insertions(+), 5 deletions(-) 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 95281da8058..96ec1709d20 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. * @@ -114,6 +119,7 @@ function PeerConnectionAnalyzer() { this._peerConnection = null this._peerDirection = null + this._peerType = null this._getStatsInterval = null @@ -154,7 +160,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 +169,7 @@ PeerConnectionAnalyzer.prototype = { this._peerConnection = peerConnection this._peerDirection = peerDirection + this._peerType = peerType this._setConnectionQualityAudio(CONNECTION_QUALITY.UNKNOWN) this._setConnectionQualityVideo(CONNECTION_QUALITY.UNKNOWN) @@ -724,8 +731,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) @@ -746,5 +762,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 7504ba348d4..a6b2b5e329f 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' @@ -3761,4 +3762,61 @@ describe('PeerConnectionAnalyzer', () => { }) }) }) + + describe('log stats', () => { + + let consoleDebugMock + + beforeEach(() => { + consoleDebugMock = jest.spyOn(console, 'debug') + }) + + test.each([ + ['video peer', 'audio'], + ['video peer', 'video'], + ])('%s, %s', (name, kind) => { + 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]') + }) + + test.each([ + ['screen peer', 'audio'], + ['screen peer', 'video'], + ])('%s, %s', (name, kind) => { + 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]') + }) + }) }) From 9e2ccae45cd1d9a747aaad6f6522649f3c2bcf46 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Daniel=20Calvi=C3=B1o=20S=C3=A1nchez?= Date: Mon, 17 Feb 2025 04:50:40 +0100 Subject: [PATCH 4/4] fix: Print RTC stats too in PeerConnectionAnalyzer logs MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The raw RTC stats provide additional information that is sometimes needed to debug the connection quality warning, so they are now included in the logs. Signed-off-by: Daniel Calviño Sánchez --- .../analyzers/PeerConnectionAnalyzer.js | 43 +++++ .../analyzers/PeerConnectionAnalyzer.spec.js | 166 ++++++++++++++++++ 2 files changed, 209 insertions(+) diff --git a/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.js b/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.js index 96ec1709d20..5c48d88a71a 100644 --- a/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.js +++ b/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.js @@ -61,6 +61,11 @@ const PEER_TYPE = { 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), @@ -289,6 +294,17 @@ PeerConnectionAnalyzer.prototype = { return } + // 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([]) + } + if (this._peerDirection === PEER_DIRECTION.SENDER) { this._processSenderStats(stats) } else if (this._peerDirection === PEER_DIRECTION.RECEIVER) { @@ -360,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 @@ -368,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 @@ -448,6 +468,8 @@ PeerConnectionAnalyzer.prototype = { } if (stat.type === 'inbound-rtp') { + this._rtcStats[stat.kind][this._rtcStats[stat.kind].length - 1].push(stat) + if ('packetsReceived' in stat && 'kind' in stat) { packetsReceived[stat.kind] = stat.packetsReceived } @@ -457,6 +479,10 @@ PeerConnectionAnalyzer.prototype = { if ('timestamp' in stat && 'kind' in stat) { timestamp[stat.kind] = stat.timestamp } + } else if (stat.type === 'remote-outbound-rtp') { + // Even if the stat is not used in calculations it is logged for + // additional context. + this._rtcStats[stat.kind][this._rtcStats[stat.kind].length - 1].push(stat) } } @@ -753,8 +779,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) diff --git a/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.spec.js b/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.spec.js index a6b2b5e329f..d107ac3d45a 100644 --- a/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.spec.js +++ b/src/utils/webrtc/analyzers/PeerConnectionAnalyzer.spec.js @@ -3775,6 +3775,8 @@ describe('PeerConnectionAnalyzer', () => { ['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) @@ -3793,12 +3795,16 @@ describe('PeerConnectionAnalyzer', () => { 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) @@ -3817,6 +3823,166 @@ describe('PeerConnectionAnalyzer', () => { 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}') + }) + + test.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) + + jest.advanceTimersByTime(9000) + // Force the promises returning the stats to be executed. + await null + + peerConnectionAnalyzer._logRtcStats(kind) + + const tag = 'PeerConnectionAnalyzer: ' + kind + + expect(consoleDebugMock).toHaveBeenCalledTimes(12) + expect(consoleDebugMock).toHaveBeenNthCalledWith(1, tag + ': {"type":"inbound-rtp","kind":"' + kind + '","id":"67890","packetsReceived":135,"timestamp":11950,"packetsLost":15}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(2, tag + ': {"type":"remote-outbound-rtp","kind":"' + kind + '","localId":"67890","packetsSent":150,"timestamp":11950}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(3, tag + ': {"type":"inbound-rtp","kind":"' + kind + '","packetsReceived":180,"timestamp":13020,"packetsLost":20,"jitter":0.007}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(4, tag + ': {"type":"remote-outbound-rtp","kind":"' + kind + '","packetsSent":200,"timestamp":13020}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(5, tag + ': no matching type') + expect(consoleDebugMock).toHaveBeenNthCalledWith(6, tag + ': {"type":"inbound-rtp","kind":"' + kind + '","packetsReceived":270,"timestamp":14985,"packetsLost":30}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(7, tag + ': {"type":"remote-outbound-rtp","kind":"' + kind + '","packetsSent":300,"timestamp":14985}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(8, tag + ': {"type":"inbound-rtp","kind":"' + kind + '","packetsReceived":315,"timestamp":16010,"packetsLost":35}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(9, tag + ': {"type":"remote-outbound-rtp","kind":"' + kind + '","packetsSent":350,"timestamp":16010}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(10, tag + ': {"type":"inbound-rtp","kind":"' + kind + '","bytesReceived":64042,"packetsReceived":400,"timestamp":17000}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(11, tag + ': {"type":"inbound-rtp","kind":"' + kind + '","packetsReceived":405,"timestamp":17990,"packetsLost":45,"codecId":"123456"}') + expect(consoleDebugMock).toHaveBeenNthCalledWith(12, tag + ': {"type":"remote-outbound-rtp","kind":"' + kind + '","packetsSent":450,"timestamp":17990}') + }) }) }) })