1587603 - Intermittent dom/media/tests/mochitest/test_dataChannel_basicAudioVideoCombined.html | Error in test execution: Error: Element _local_{5f43014a-9433-4675-adc7-6cbe67623cd2} should progress currentTime timeout

Status: RESOLVED INCOMPLETE

(Core :: WebRTC, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: ncsoregi [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=270450946&repo=mozilla-beta
Full log: https://queue.taskcluster.net/v1/task/Aa0cAdXvTyyJuLKwiSojzQ/runs/0/artifacts/public/logs/live_backing.log

---

[task 2019-10-09T11:44:15.067Z] 11:44:15 INFO - TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideoCombined.html | RTP flowing for audio track {5f43014a-9433-4675-adc7-6cbe67623cd2}
[task 2019-10-09T11:44:15.068Z] 11:44:15 INFO - Checking for stats in [["outbound_rtp_video_0",{"id":"outbound_rtp_video_0","timestamp":1570621394957,"type":"outbound-rtp","kind":"video","mediaType":"video","ssrc":1035522829,"bytesSent":1260,"packetsSent":3,"bitrateMean":1e-323,"bitrateStdDev":3.861379571646e-312,"droppedFrames":0,"firCount":0,"framerateMean":0,"framerateStdDev":6.9520237313771e-310,"framesEncoded":0,"nackCount":0,"pliCount":0,"remoteId":""}],["eRoA",{"id":"eRoA","timestamp":1570621394957,"type":"candidate-pair","bytesReceived":3396,"bytesSent":3383,"componentId":1,"lastPacketReceivedTimestamp":330193106951,"lastPacketSentTimestamp":330193106956,"localCandidateId":"y8oJ","nominated":true,"priority":9115005270282338000,"readable":true,"remoteCandidateId":"7tk7","selected":true,"state":"succeeded","transportId":"transport_0","writable":true}],["SKwP",{"id":"SKwP","timestamp":1570621394957,"type":"candidate-pair","bytesReceived":0,"bytesSent":0,"componentId":1,"lastPacketReceivedTimestamp":0,"lastPacketSentTimestamp":0,"localCandidateId":"y8oJ","nominated":true,"priority":7962083765675491000,"readable":true,"remoteCandidateId":"hGIO","selected":false,"state":"succeeded","transportId":"transport_0","writable":true}],["y8oJ",{"id":"y8oJ","timestamp":1570621394957,"type":"local-candidate","address":"10.145.79.238","candidateType":"host","port":52976,"priority":2122252543,"protocol":"udp","proxied":"non-proxied"}],["wUSb",{"id":"wUSb","timestamp":1570621394957,"type":"local-candidate","address":"10.145.79.238","candidateType":"host","port":58817,"priority":2105524479,"protocol":"tcp","proxied":"non-proxied"}],["hGIO",{"id":"hGIO","timestamp":1570621394957,"type":"remote-candidate","address":"10.145.79.238","candidateType":"prflx","port":52982,"priority":1853817087,"protocol":"udp","proxied":"non-proxied"}],["7tk7",{"id":"7tk7","timestamp":1570621394957,"type":"remote-candidate","address":"10.145.79.238","candidateType":"host","port":52982,"priority":2122252543,"protocol":"udp","proxied":"non-proxied"}],["wHhW",{"id":"wHhW","timestamp":1570621394957,"type":"remote-candidate","address":"10.145.79.238","candidateType":"host","port":9,"priority":2105524479,"protocol":"tcp","proxied":"non-proxied"}]] for video track {91c2adc3-b196-490c-bc86-20ad99b613da}retry number 0
[task 2019-10-09T11:44:15.068Z] 11:44:15 INFO - Should have RTP stats for track {91c2adc3-b196-490c-bc86-20ad99b613da}
[task 2019-10-09T11:44:15.068Z] 11:44:15 INFO - RTP stats: {"id":"outbound_rtp_video_0","timestamp":1570621394957,"type":"outbound-rtp","kind":"video","mediaType":"video","ssrc":1035522829,"bytesSent":1260,"packetsSent":3,"bitrateMean":1e-323,"bitrateStdDev":3.861379571646e-312,"droppedFrames":0,"firCount":0,"framerateMean":0,"framerateStdDev":6.9520237313771e-310,"framesEncoded":0,"nackCount":0,"pliCount":0,"remoteId":""}
[task 2019-10-09T11:44:15.069Z] 11:44:15 INFO - Track {91c2adc3-b196-490c-bc86-20ad99b613da} has 3 outbound-rtp RTP packets.
[task 2019-10-09T11:44:15.069Z] 11:44:15 INFO - TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideoCombined.html | RTP flowing for video track {91c2adc3-b196-490c-bc86-20ad99b613da}
[task 2019-10-09T11:44:15.070Z] 11:44:15 INFO - Element remote{38018526-4b9c-4d70-932d-725f7e679d26} has enough data.
[task 2019-10-09T11:44:15.070Z] 11:44:15 INFO - Buffered messages logged at 11:43:15
[task 2019-10-09T11:44:15.071Z] 11:44:15 INFO - Checking for stats in [["inbound_rtp_video_0",{"id":"inbound_rtp_video_0","timestamp":1570621395452,"type":"inbound-rtp","kind":"video","mediaType":"video","ssrc":0,"discardedPackets":0,"jitter":0,"packetsLost":0,"packetsReceived":39,"bitrateMean":0,"bitrateStdDev":6.9520237313771e-310,"bytesReceived":11839,"firCount":0,"framerateMean":0,"framerateStdDev":1.4259811715287e-311,"framesDecoded":0,"nackCount":0,"pliCount":0,"remoteId":"inbound_rtcp_video_0"}],["inbound_rtcp_video_0",{"id":"inbound_rtcp_video_0","timestamp":1570621395452,"type":"remote-outbound-rtp","kind":"video","mediaType":"video","ssrc":0,"bytesSent":0,"packetsSent":0,"localId":"inbound_rtp_video_0"}],["eRoA",{"id":"eRoA","timestamp":1570621395452,"type":"candidate-pair","bytesReceived":16319,"bytesSent":15278,"componentId":1,"lastPacketReceivedTimestamp":330193107434,"lastPacketSentTimestamp":330193107438,"localCandidateId":"y8oJ","nominated":true,"priority":9115005270282338000,"readable":true,"remoteCandidateId":"7tk7","selected":true,"state":"succeeded","transportId":"transport_0","writable":true}],["SKwP",{"id":"SKwP","timestamp":1570621395452,"type":"candidate-pair","bytesReceived":0,"bytesSent":0,"componentId":1,"lastPacketReceivedTimestamp":0,"lastPacketSentTimestamp":0,"localCandidateId":"y8oJ","nominated":true,"priority":7962083765675491000,"readable":true,"remoteCandidateId":"hGIO","selected":false,"state":"succeeded","transportId":"transport_0","writable":true}],["y8oJ",{"id":"y8oJ","timestamp":1570621395452,"type":"local-candidate","address":"10.145.79.238","candidateType":"host","port":52976,"priority":2122252543,"protocol":"udp","proxied":"non-proxied"}],["wUSb",{"id":"wUSb","timestamp":1570621395452,"type":"local-candidate","address":"10.145.79.238","candidateType":"host","port":58817,"priority":2105524479,"protocol":"tcp","proxied":"non-proxied"}],["hGIO",{"id":"hGIO","timestamp":1570621395452,"type":"remote-candidate","address":"10.145.79.238","candidateType":"prflx","port":52982,"priority":1853817087,"protocol":"udp","proxied":"non-proxied"}],["7tk7",{"id":"7tk7","timestamp":1570621395452,"type":"remote-candidate","address":"10.145.79.238","candidateType":"host","port":52982,"priority":2122252543,"protocol":"udp","proxied":"non-proxied"}],["wHhW",{"id":"wHhW","timestamp":1570621395452,"type":"remote-candidate","address":"10.145.79.238","candidateType":"host","port":9,"priority":2105524479,"protocol":"tcp","proxied":"non-proxied"}]] for video track {38018526-4b9c-4d70-932d-725f7e679d26}retry number 1
[task 2019-10-09T11:44:15.072Z] 11:44:15 INFO - Should have RTP stats for track {38018526-4b9c-4d70-932d-725f7e679d26}
[task 2019-10-09T11:44:15.072Z] 11:44:15 INFO - RTP stats: {"id":"inbound_rtp_video_0","timestamp":1570621395452,"type":"inbound-rtp","kind":"video","mediaType":"video","ssrc":0,"discardedPackets":0,"jitter":0,"packetsLost":0,"packetsReceived":39,"bitrateMean":0,"bitrateStdDev":6.9520237313771e-310,"bytesReceived":11839,"firCount":0,"framerateMean":0,"framerateStdDev":1.4259811715287e-311,"framesDecoded":0,"nackCount":0,"pliCount":0,"remoteId":"inbound_rtcp_video_0"}
[task 2019-10-09T11:44:15.073Z] 11:44:15 INFO - Track {38018526-4b9c-4d70-932d-725f7e679d26} has 39 inbound-rtp RTP packets.
[task 2019-10-09T11:44:15.073Z] 11:44:15 INFO - TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideoCombined.html | RTP flowing for video track {38018526-4b9c-4d70-932d-725f7e679d26}
[task 2019-10-09T11:44:15.073Z] 11:44:15 INFO - Buffered messages finished
[task 2019-10-09T11:44:15.074Z] 11:44:15 INFO - TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_dataChannel_basicAudioVideoCombined.html | Error in test execution: Error: Element local{5f43014a-9433-4675-adc7-6cbe67623cd2} should progress currentTime timeout/<@https://example.com/tests/dom/media/tests/mochitest/head.js:652:42 ...
[task 2019-10-09T11:44:15.074Z] 11:44:15 INFO - SimpleTest.ok@https://example.com/tests/SimpleTest/SimpleTest.js:277:18
[task 2019-10-09T11:44:15.074Z] 11:44:15 INFO - execute/<@https://example.com/tests/dom/media/tests/mochitest/head.js:948:11
[task 2019-10-09T11:44:15.075Z] 11:44:15 INFO - closeDataChannels called with index: 0
[task 2019-10-09T11:44:15.075Z] 11:44:15 INFO - TEST-FAIL | dom/media/tests/mochitest/test_dataChannel_basicAudioVideoCombined.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts

Comment 1

[Intermittent Failures Robot]

1 failures in 3801 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 1

Platform breakdown:

• windows10-64-shippable-qr: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1587603&startday=2019-10-07&endday=2019-10-13&tree=all

Comment 2

[BugBot [:suhaib / :marco/ :calixte]]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Comment 3

[Cristian Brindusan [:cbrindusan]]

New occurrence:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=294260452&repo=autoland&lineNumber=18331

Comment 4

[Intermittent Failures Robot]

1 failures in 4955 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform breakdown:

• windows10-64-qr: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1587603&startday=2020-03-16&endday=2020-03-22&tree=all

Comment 5

[Intermittent Failures Robot]

1 failures in 4823 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform breakdown:

• windows10-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1587603&startday=2020-04-06&endday=2020-04-12&tree=all

Comment 6

[BugBot [:suhaib / :marco/ :calixte]]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.