Closed Bug 1457129 Opened 2 years ago Closed 1 year ago

Intermittent /webrtc/RTCPeerConnection-track-stats.https.html | RTCPeerConnection.getStats(receivingTrack) is the same as RTCRtpReceiver.getStats() - assert_true: expected true got false

Categories

(Core :: WebRTC, defect, P5)

defect

Tracking

()

RESOLVED FIXED
mozilla65
Tracking Status
firefox64 --- fixed
firefox65 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: ng, NeedInfo)

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell unknown][stockwell needswork][wptsync upstream])

Attachments

(1 file)

This bug failed 39 times in the last week. Failures happen on all platforms and all build types, except android.

Here is a recent log:
https://treeherder.mozilla.org/logviewer.html#?job_id=192897593&repo=autoland&lineNumber=43404

 TEST-PASS | /webrtc/RTCPeerConnection-track-stats.https.html | RTCPeerConnection.getStats(sendingTrack) is the same as RTCRtpSender.getStats() 
[task 2018-08-09T00:40:55.054Z] 00:40:55     INFO - TEST-UNEXPECTED-FAIL | /webrtc/RTCPeerConnection-track-stats.https.html | RTCPeerConnection.getStats(receivingTrack) is the same as RTCRtpReceiver.getStats() - assert_true: expected true got false
[task 2018-08-09T00:40:55.055Z] 00:40:55     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:545:7
[task 2018-08-09T00:40:55.056Z] 00:40:55     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:544:5
[task 2018-08-09T00:40:55.056Z] 00:40:55     INFO - async*Test.prototype.step@https://web-platform.test:8443/resources/testharness.js:1538:20
[task 2018-08-09T00:40:55.057Z] 00:40:55     INFO - promise_test/tests.promise_tests<@https://web-platform.test:8443/resources/testharness.js:577:27
[task 2018-08-09T00:40:55.057Z] 00:40:55     INFO - promise callback*promise_test@https://web-platform.test:8443/resources/testharness.js:573:31
[task 2018-08-09T00:40:55.057Z] 00:40:55     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:522:3
[task 2018-08-09T00:40:55.058Z] 00:40:55     INFO - ..
[task 2018-08-09T00:40:55.059Z] 00:40:55     INFO - TEST-OK | /webrtc/RTCPeerConnection-track-stats.https.html | took 2811ms

:drno: Can you please take a look at this bug?
Flags: needinfo?(drno)
Whiteboard: [stockwell needswork]
Nico since you are our stats expert can I ask you to have a look at this?
Flags: needinfo?(drno) → needinfo?(na-g)
Assignee: nobody → na-g
Flags: needinfo?(na-g)
This test is not written to account for RTCP stats which show up some time after media is flowing. What is likely happening, is that some RTCP stats are appearing in the second call to get stats that were not in the first. Either complete RTCP stats should be waited for, or they should be filtered out before the check.
In the last 7 days, there are 35 failures associated with this bug. They occur on linux64 and osx-10-10, all build types.

Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=196356536&repo=autoland&lineNumber=31374
Flags: needinfo?(na-g)
Update:
There have been 31 failures in the last week.
The most affected build type is debug.

Failures per platform: 
linux64: 16
osx-10-10: 12
linux64-qr: 1
windows10-64: 1
windows10-64-nightly: 1


Recent relevant log file
https://treeherder.mozilla.org/logviewer.html#?job_id=197675991&repo=mozilla-inbound&lineNumber=42364
	
[task 2018-09-05T20:10:07.022Z] 20:10:07     INFO - TEST-FAIL | /webrtc/RTCPeerConnection-track-stats.https.html | RTCRtpSender.getStats() contains only outbound-rtp and related stats - promise_test: Unhandled rejection with value: object "TypeError: outboundTrackStats is null, can't access property "id" of it"
[task 2018-09-05T20:10:07.022Z] 20:10:07     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:399:3
[task 2018-09-05T20:10:07.022Z] 20:10:07     INFO - TEST-FAIL | /webrtc/RTCPeerConnection-track-stats.https.html | RTCRtpReceiver.getStats() contains only inbound-rtp and related stats - promise_test: Unhandled rejection with value: object "TypeError: outboundTrackStats is null, can't access property "id" of it"
[task 2018-09-05T20:10:07.023Z] 20:10:07     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:447:3
[task 2018-09-05T20:10:07.023Z] 20:10:07     INFO - TEST-PASS | /webrtc/RTCPeerConnection-track-stats.https.html | RTCPeerConnection.getStats(sendingTrack) is the same as RTCRtpSender.getStats() 
[task 2018-09-05T20:10:07.023Z] 20:10:07     INFO - TEST-UNEXPECTED-FAIL | /webrtc/RTCPeerConnection-track-stats.https.html | RTCPeerConnection.getStats(receivingTrack) is the same as RTCRtpReceiver.getStats() - assert_true: expected true got false
[task 2018-09-05T20:10:07.023Z] 20:10:07     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:545:7
[task 2018-09-05T20:10:07.023Z] 20:10:07     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:544:5
[task 2018-09-05T20:10:07.024Z] 20:10:07     INFO - async*Test.prototype.step@https://web-platform.test:8443/resources/testharness.js:1553:20
[task 2018-09-05T20:10:07.024Z] 20:10:07     INFO - promise_test/tests.promise_tests</<@https://web-platform.test:8443/resources/testharness.js:576:31
[task 2018-09-05T20:10:07.024Z] 20:10:07     INFO - promise_test/tests.promise_tests<@https://web-platform.test:8443/resources/testharness.js:575:20
[task 2018-09-05T20:10:07.025Z] 20:10:07     INFO - promise callback*promise_test@https://web-platform.test:8443/resources/testharness.js:574:31
[task 2018-09-05T20:10:07.025Z] 20:10:07     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:522:3
Status: NEW → ASSIGNED
Flags: needinfo?(na-g)
If care is not taken to wait for remote stats on senders and receivers, then the contents
of the stats reports will not be stable. Waiting for this stability should fix our
intermittent failures checking that RTCRtpSender/Receiver.getStats() returns the
same dictionaries that RTCPeerConnection.getStats(sender/receiver.track) does.
In the last 7 days there are 33 failures, most on Linux and OSX, debug, opt and pgo.
Whiteboard: [stockwell unknown] → [stockwell unknown][stockwell needswork]
This bug has failed 37 times in the last 7 days. Occurs on linux32, linux64, linux64-qr, osx-10-10 and windows10-64 on pgo, opt and debug.

Log:
https://treeherder.mozilla.org/logviewer.html#?job_id=206764296&repo=mozilla-central&lineNumber=27434

INFO - TEST-FAIL | /webrtc/RTCPeerConnection-track-stats.https.html | Legacy addStream(): Media stream stats references track stats - assert_true: Has stats for track and stream expected true got false
[task 2018-10-20T10:47:55.665Z] 10:47:55     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:183:7
[task 2018-10-20T10:47:55.666Z] 10:47:55     INFO - Test.prototype.step@https://web-platform.test:8443/resources/testharness.js:1561:20
[task 2018-10-20T10:47:55.667Z] 10:47:55     INFO - Test.prototype.step_func/<@https://web-platform.test:8443/resources/testharness.js:1585:20
[task 2018-10-20T10:47:55.668Z] 10:47:55     INFO - promise callback*@https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:180:6
[task 2018-10-20T10:47:55.669Z] 10:47:55     INFO - Test.prototype.step@https://web-platform.test:8443/resources/testharness.js:1561:20
[task 2018-10-20T10:47:55.670Z] 10:47:55     INFO - async_test@https://web-platform.test:8443/resources/testharness.js:576:13
[task 2018-10-20T10:47:55.671Z] 10:47:55     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:161:3
[task 2018-10-20T10:47:55.672Z] 10:47:55     INFO - TEST-FAIL | /webrtc/RTCPeerConnection-track-stats.https.html | O/A exchange yields outbound RTP stream stats for sending track - Not enough arguments to RTCPeerConnection.addTrack.
[task 2018-10-20T10:47:55.673Z] 10:47:55     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:205:7
[task 2018-10-20T10:47:55.674Z] 10:47:55     INFO - Test.prototype.step@https://web-platform.test:8443/resources/testharness.js:1561:20
[task 2018-10-20T10:47:55.674Z] 10:47:55     INFO - Test.prototype.step_func/<@https://web-platform.test:8443/resources/testharness.js:1585:20
[task 2018-10-20T10:47:55.675Z] 10:47:55     INFO - promise callback*@https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:203:6
[task 2018-10-20T10:47:55.677Z] 10:47:55     INFO - Test.prototype.step@https://web-platform.test:8443/resources/testharness.js:1561:20
[task 2018-10-20T10:47:55.678Z] 10:47:55     INFO - async_test@https://web-platform.test:8443/resources/testharness.js:576:13
[task 2018-10-20T10:47:55.679Z] 10:47:55     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:196:3
[task 2018-10-20T10:47:55.680Z] 10:47:55     INFO - TEST-FAIL | /webrtc/RTCPeerConnection-track-stats.https.html | O/A exchange yields inbound RTP stream stats for receiving track - Not enough arguments to RTCPeerConnection.addTrack.
[task 2018-10-20T10:47:55.681Z] 10:47:55     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:238:7
[task 2018-10-20T10:47:55.682Z] 10:47:55     INFO - Test.prototype.step@https://web-platform.test:8443/resources/testharness.js:1561:20
[task 2018-10-20T10:47:55.683Z] 10:47:55     INFO - Test.prototype.step_func/<@https://web-platform.test:8443/resources/testharness.js:1585:20
[task 2018-10-20T10:47:55.684Z] 10:47:55     INFO - promise callback*@https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:237:6
[task 2018-10-20T10:47:55.685Z] 10:47:55     INFO - Test.prototype.step@https://web-platform.test:8443/resources/testharness.js:1561:20
[task 2018-10-20T10:47:55.685Z] 10:47:55     INFO - async_test@https://web-platform.test:8443/resources/testharness.js:576:13
[task 2018-10-20T10:47:55.685Z] 10:47:55     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:226:3
[task 2018-10-20T10:47:55.686Z] 10:47:55     INFO - TEST-FAIL | /webrtc/RTCPeerConnection-track-stats.https.html | replaceTrack() before offer: new track attachment stats present - Not enough arguments to RTCPeerConnection.addTrack.
[task 2018-10-20T10:47:55.686Z] 10:47:55     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:272:16
[task 2018-10-20T10:47:55.686Z] 10:47:55     INFO - Test.prototype.step@https://web-platform.test:8443/resources/testharness.js:1561:20
[task 2018-10-20T10:47:55.687Z] 10:47:55     INFO - Test.prototype.step_func/<@https://web-platform.test:8443/resources/testharness.js:1585:20
[task 2018-10-20T10:47:55.687Z] 10:47:55     INFO - promise callback*@https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:269:6
[task 2018-10-20T10:47:55.688Z] 10:47:55     INFO - Test.prototype.step@https://web-platform.test:8443/resources/testharness.js:1561:20
[task 2018-10-20T10:47:55.689Z] 10:47:55     INFO - async_test@https://web-platform.test:8443/resources/testharness.js:576:13
[task 2018-10-20T10:47:55.690Z] 10:47:55     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:260:3
[task 2018-10-20T10:47:55.691Z] 10:47:55     INFO - TEST-FAIL | /webrtc/RTCPeerConnection-track-stats.https.html | replaceTrack() after offer, before answer: new track attachment stats present - Not enough arguments to RTCPeerConnection.addTrack.
[task 2018-10-20T10:47:55.692Z] 10:47:55     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:301:16
[task 2018-10-20T10:47:55.693Z] 10:47:55     INFO - Test.prototype.step@https://web-platform.test:8443/resources/testharness.js:1561:20
[task 2018-10-20T10:47:55.693Z] 10:47:55     INFO - Test.prototype.step_func/<@https://web-platform.test:8443/resources/testharness.js:1585:20
[task 2018-10-20T10:47:55.695Z] 10:47:55     INFO - promise callback*@https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:298:6
[task 2018-10-20T10:47:55.696Z] 10:47:55     INFO - Test.prototype.step@https://web-platform.test:8443/resources/testharness.js:1561:20
[task 2018-10-20T10:47:55.696Z] 10:47:55     INFO - async_test@https://web-platform.test:8443/resources/testharness.js:576:13
[task 2018-10-20T10:47:55.698Z] 10:47:55     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:289:3
[task 2018-10-20T10:47:55.699Z] 10:47:55     INFO - TEST-FAIL | /webrtc/RTCPeerConnection-track-stats.https.html | replaceTrack() after answer: new track attachment stats present - Not enough arguments to RTCPeerConnection.addTrack.
[task 2018-10-20T10:47:55.699Z] 10:47:55     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:338:16
[task 2018-10-20T10:47:55.700Z] 10:47:55     INFO - Test.prototype.step@https://web-platform.test:8443/resources/testharness.js:1561:20
[task 2018-10-20T10:47:55.701Z] 10:47:55     INFO - Test.prototype.step_func/<@https://web-platform.test:8443/resources/testharness.js:1585:20
[task 2018-10-20T10:47:55.703Z] 10:47:55     INFO - promise callback*@https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:335:6
[task 2018-10-20T10:47:55.704Z] 10:47:55     INFO - Test.prototype.step@https://web-platform.test:8443/resources/testharness.js:1561:20
[task 2018-10-20T10:47:55.705Z] 10:47:55     INFO - async_test@https://web-platform.test:8443/resources/testharness.js:576:13
[task 2018-10-20T10:47:55.706Z] 10:47:55     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:326:3
[task 2018-10-20T10:47:55.707Z] 10:47:55     INFO - TEST-FAIL | /webrtc/RTCPeerConnection-track-stats.https.html | replaceTrack(): original track attachment stats present after replacing - Not enough arguments to RTCPeerConnection.addTrack.
[task 2018-10-20T10:47:55.709Z] 10:47:55     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:374:16
[task 2018-10-20T10:47:55.709Z] 10:47:55     INFO - Test.prototype.step@https://web-platform.test:8443/resources/testharness.js:1561:20
[task 2018-10-20T10:47:55.709Z] 10:47:55     INFO - Test.prototype.step_func/<@https://web-platform.test:8443/resources/testharness.js:1585:20
[task 2018-10-20T10:47:55.713Z] 10:47:55     INFO - promise callback*@https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:371:6
[task 2018-10-20T10:47:55.713Z] 10:47:55     INFO - Test.prototype.step@https://web-platform.test:8443/resources/testharness.js:1561:20
[task 2018-10-20T10:47:55.714Z] 10:47:55     INFO - async_test@https://web-platform.test:8443/resources/testharness.js:576:13
[task 2018-10-20T10:47:55.714Z] 10:47:55     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:362:3
[task 2018-10-20T10:47:55.715Z] 10:47:55     INFO - TEST-FAIL | /webrtc/RTCPeerConnection-track-stats.https.html | RTCRtpSender.getStats() contains only outbound-rtp and related stats - promise_test: Unhandled rejection with value: object "TypeError: outboundTrackStats is null; can't access its "id" property"
[task 2018-10-20T10:47:55.715Z] 10:47:55     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:399:3
[task 2018-10-20T10:47:55.716Z] 10:47:55     INFO - TEST-FAIL | /webrtc/RTCPeerConnection-track-stats.https.html | RTCRtpReceiver.getStats() contains only inbound-rtp and related stats - promise_test: Unhandled rejection with value: object "TypeError: outboundTrackStats is null; can't access its "id" property"
[task 2018-10-20T10:47:55.719Z] 10:47:55     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:447:3
[task 2018-10-20T10:47:55.721Z] 10:47:55     INFO - TEST-PASS | /webrtc/RTCPeerConnection-track-stats.https.html | RTCPeerConnection.getStats(sendingTrack) is the same as RTCRtpSender.getStats() 
[task 2018-10-20T10:47:55.722Z] 10:47:55     INFO - TEST-UNEXPECTED-FAIL | /webrtc/RTCPeerConnection-track-stats.https.html | RTCPeerConnection.getStats(receivingTrack) is the same as RTCRtpReceiver.getStats() - assert_true: expected true got false
[task 2018-10-20T10:47:55.722Z] 10:47:55     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:545:7
[task 2018-10-20T10:47:55.723Z] 10:47:55     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:544:5
[task 2018-10-20T10:47:55.723Z] 10:47:55     INFO - async*Test.prototype.step@https://web-platform.test:8443/resources/testharness.js:1561:20
[task 2018-10-20T10:47:55.723Z] 10:47:55     INFO - promise_test/tests.promise_tests</<@https://web-platform.test:8443/resources/testharness.js:591:31
[task 2018-10-20T10:47:55.724Z] 10:47:55     INFO - promise_test/tests.promise_tests<@https://web-platform.test:8443/resources/testharness.js:590:20
[task 2018-10-20T10:47:55.728Z] 10:47:55     INFO - promise callback*promise_test@https://web-platform.test:8443/resources/testharness.js:589:31
[task 2018-10-20T10:47:55.729Z] 10:47:55     INFO - @https://web-platform.test:8443/webrtc/RTCPeerConnection-track-stats.https.html:522:3
[task 2018-10-20T10:47:55.730Z] 10:47:55     INFO - ..
[task 2018-10-20T10:47:55.730Z] 10:47:55     INFO - TEST-OK | /webrtc/RTCPeerConnection-track-stats.https.html | took 1221ms

drno: Can you please take a look?
Flags: needinfo?(drno)
Pushed by na-g@nostrum.com:
https://hg.mozilla.org/integration/autoland/rev/0874b793fc04
Correct WebRTC getStats WPT to wait for remote stats before comparing r=jib
Created web-platform-tests PR https://github.com/web-platform-tests/wpt/pull/13942 for changes under testing/web-platform/tests
Whiteboard: [stockwell unknown][stockwell needswork] → [stockwell unknown][stockwell needswork][wptsync upstream]
Whiteboard: [stockwell unknown][stockwell needswork][wptsync upstream] → [stockwell unknown][stockwell needswork][wptsync upstream error]
https://hg.mozilla.org/mozilla-central/rev/0874b793fc04
Status: ASSIGNED → RESOLVED
Closed: 1 year ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla65
Whiteboard: [stockwell unknown][stockwell needswork][wptsync upstream error] → [stockwell unknown][stockwell needswork][wptsync upstream]
A bunch of the failures in comment 47 are actually bug 1487278.
Upstream PR merged
You need to log in before you can comment on or make changes to this bug.