1610544 - Intermittent dom/media/tests/mochitest/identity/test_peerConnection_peerIdentity.html | Error in test execution: Error: Element _local_{aa1e6cc6-9b7a-4715-a539-bdd5337149d2} should progress currentTime timeout/

Status: RESOLVED INCOMPLETE

(Core :: WebRTC, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: apavel [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=285737771&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/MkRh3bqlT9KhAgR37oSujg/runs/0/artifacts/public/logs/live_backing.log

---

[task 2020-01-21T09:39:38.704Z] 09:39:38 INFO - GECKO(11012) | [Child 6208, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannel, this is likely broken: file z:/build/build/src/netwerk/ipc/DocumentChannel.cpp, line 63
[task 2020-01-21T09:39:38.742Z] 09:39:38 INFO - TEST-START | dom/media/tests/mochitest/identity/test_peerConnection_peerIdentity.html
[task 2020-01-21T09:39:38.761Z] 09:39:38 INFO - GECKO(11012) | [Child 6208, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannel, this is likely broken: file z:/build/build/src/netwerk/ipc/DocumentChannel.cpp, line 63
[task 2020-01-21T09:39:38.863Z] 09:39:38 INFO - GECKO(11012) | TEST DEVICES: No test device found in media.audio_loopback_dev, using fake audio streams.
[task 2020-01-21T09:39:38.863Z] 09:39:38 INFO - GECKO(11012) | TEST DEVICES: No test device found in media.video_loopback_dev, using fake video streams.
[task 2020-01-21T09:39:38.983Z] 09:39:38 INFO - GECKO(11012) | Timecard created 1579599577.089000

[task 2020-01-21T09:40:39.988Z] 09:40:39 INFO - TEST-PASS | dom/media/tests/mochitest/identity/test_peerConnection_peerIdentity.html | RTP flowing for video track {5ae8145b-416f-4585-97df-202de850e9f8}
[task 2020-01-21T09:40:39.989Z] 09:40:39 INFO - Checking for stats in [["c3e11dcf",{"id":"c3e11dcf","timestamp":1579599580400,"type":"candidate-pair","bytesReceived":12402,"bytesSent":12546,"lastPacketReceivedTimestamp":339171292375,"lastPacketSentTimestamp":339171292371,"localCandidateId":"48fd093f","nominated":true,"priority":7962083765675491000,"readable":true,"remoteCandidateId":"956d6ee4","selected":true,"state":"succeeded","transportId":"transport_0","writable":true}],["48fd093f",{"id":"48fd093f","timestamp":1579599580400,"type":"local-candidate","address":"59769f7e-0eef-4ee7-84d2-d15569080ff8.local","candidateType":"host","port":59659,"priority":2122252543,"protocol":"udp"}],["87fecd29",{"id":"87fecd29","timestamp":1579599580400,"type":"local-candidate","address":"59769f7e-0eef-4ee7-84d2-d15569080ff8.local","candidateType":"host","port":54078,"priority":2105524479,"protocol":"tcp"}],["956d6ee4",{"id":"956d6ee4","timestamp":1579599580400,"type":"remote-candidate","address":"(redacted)","candidateType":"prflx","port":59664,"priority":1853817087,"protocol":"udp"}],["7905d42c",{"id":"7905d42c","timestamp":1579599580401,"type":"outbound-rtp","kind":"video","mediaType":"video","ssrc":2091820800,"bytesSent":10342,"packetsSent":40,"bitrateMean":null,"bitrateStdDev":null,"droppedFrames":0,"firCount":0,"framerateMean":null,"framerateStdDev":null,"framesEncoded":0,"nackCount":0,"pliCount":0}]] for video track {32241e98-15fe-4b18-a9cd-d575e0f5abd4}retry number 1
[task 2020-01-21T09:40:39.989Z] 09:40:39 INFO - Should have RTP stats for track {32241e98-15fe-4b18-a9cd-d575e0f5abd4}
[task 2020-01-21T09:40:39.990Z] 09:40:39 INFO - RTP stats: {"id":"7905d42c","timestamp":1579599580401,"type":"outbound-rtp","kind":"video","mediaType":"video","ssrc":2091820800,"bytesSent":10342,"packetsSent":40,"bitrateMean":null,"bitrateStdDev":null,"droppedFrames":0,"firCount":0,"framerateMean":null,"framerateStdDev":null,"framesEncoded":0,"nackCount":0,"pliCount":0}
[task 2020-01-21T09:40:39.990Z] 09:40:39 INFO - Track {32241e98-15fe-4b18-a9cd-d575e0f5abd4} has 40 outbound-rtp RTP packets.
[task 2020-01-21T09:40:39.990Z] 09:40:39 INFO - TEST-PASS | dom/media/tests/mochitest/identity/test_peerConnection_peerIdentity.html | RTP flowing for video track {32241e98-15fe-4b18-a9cd-d575e0f5abd4}
[task 2020-01-21T09:40:39.990Z] 09:40:39 INFO - Buffered messages finished
[task 2020-01-21T09:40:39.990Z] 09:40:39 INFO - TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/identity/test_peerConnection_peerIdentity.html | Error in test execution: Error: Element local{aa1e6cc6-9b7a-4715-a539-bdd5337149d2} should progress currentTime timeout/<@https://example.com/tests/dom/media/tests/mochitest/head.js:657:42 ... promise callbacktimeout@https://example.com/tests/dom/media/tests/mochitest/head.js:657:16 ... waitForMediaElementFlow@https://example.com/tests/dom/media/tests/mochitest/pc.js:1782:35 ... waitForMediaFlow/<@https://example.com/tests/dom/media/tests/mochitest/pc.js:1897:16 ... waitForMediaFlow@https://example.com/tests/dom/media/tests/mochitest/pc.js:1896:33 ... PC_LOCAL_WAIT_FOR_MEDIA_FLOW@https://example.com/tests/dom/media/tests/mochitest/templates.js:513:25 ... execute/</<@https://example.com/tests/dom/media/tests/mochitest/head.js:949:32 ...
[task 2020-01-21T09:40:39.990Z] 09:40:39 INFO - SimpleTest.ok@https://example.com/tests/SimpleTest/SimpleTest.js:277:18
[task 2020-01-21T09:40:39.991Z] 09:40:39 INFO - execute/<@https://example.com/tests/dom/media/tests/mochitest/head.js:953:11
[task 2020-01-21T09:40:39.991Z] 09:40:39 INFO - promise callbackexecute@https://example.com/tests/dom/media/tests/mochitest/head.js:952:8
[task 2020-01-21T09:40:39.991Z] 09:40:39 INFO - PeerConnectionTest.prototype.run@https://example.com/tests/dom/media/tests/mochitest/pc.js:574:6
[task 2020-01-21T09:40:39.991Z] 09:40:39 INFO - identityPcTest@https://example.com/tests/dom/media/tests/mochitest/identity/identityPcTest.js:78:8
[task 2020-01-21T09:40:39.991Z] 09:40:39 INFO - runNetworkTest/<@https://example.com/tests/dom/media/tests/mochitest/pc.js:2556:11
[task 2020-01-21T09:40:39.991Z] 09:40:39 INFO - asyncrunTestWhenReady/<@https://example.com/tests/dom/media/tests/mochitest/head.js:497:30
[task 2020-01-21T09:40:39.991Z] 09:40:39 INFO - promise callbackrunTestWhenReady@https://example.com/tests/dom/media/tests/mochitest/head.js:497:6
[task 2020-01-21T09:40:39.991Z] 09:40:39 INFO - runNetworkTest@https://example.com/tests/dom/media/tests/mochitest/pc.js:2537:9
[task 2020-01-21T09:40:39.991Z] 09:40:39 INFO - async*@https://example.com/tests/dom/media/tests/mochitest/identity/test_peerConnection_peerIdentity.html:17:15
[task 2020-01-21T09:40:39.991Z] 09:40:39 INFO - TEST-FAIL | dom/media/tests/mochitest/identity/test_peerConnection_peerIdentity.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts
[task 2020-01-21T09:40:39.991Z] 09:40:39 INFO - Closing peer connections
[task 2020-01-21T09:40:39.991Z] 09:40:39 INFO - Waiting for track {b9552e31-91a0-45d7-8791-af799fd49591} (audio) to end.
[task 2020-01-21T09:40:39.991Z] 09:40:39 INFO - TEST-FAIL | dom/media/tests/mochitest/identity/test_peerConnection_peerIdentity.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts
[task 2020-01-21T09:40:39.991Z] 09:40:39 INFO - Waiting for track {5ae8145b-416f-4585-97df-202de850e9f8} (video) to end.
[task 2020-01-21T09:40:39.991Z] 09:40:39 INFO - TEST-FAIL | dom/media/tests/mochitest/identity/test_peerConnection_peerIdentity.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts
[task 2020-01-21T09:40:39.992Z] 09:40:39 INFO - TEST-PASS | dom/media/tests/mochitest/identity/test_peerConnection_peerIdentity.html | iceConnectionState should not be undefined
[task 2020-01-21T09:40:39.992Z] 09:40:39 INFO - PeerConnectionWrapper (pcLocal): oniceconnectionstatechange fired, new state is: closed

Comment 1

[Intermittent Failures Robot]

1 failures in 4004 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=1610544&startday=2020-01-20&endday=2020-01-26&tree=all

Comment 2

[Intermittent Failures Robot]

1 failures in 4690 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=1610544&startday=2020-02-10&endday=2020-02-16&tree=all

Comment 3

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

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

Comment 4

[Noemi Erli[:noemi_erli]]

Recent failure: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=304091070&repo=autoland&lineNumber=6562

Comment 5

[Intermittent Failures Robot]

1 failures in 5458 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=1610544&startday=2020-05-25&endday=2020-05-31&tree=all

Comment 6

[Intermittent Failures Robot]

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

Repository breakdown:

• try: 1
• mozilla-central: 1

Platform breakdown:

• windows10-64-devedition: 1
• windows10-64-qr: 1

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

Comment 7

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1

Platform breakdown:

• windows10-64-qr: 1

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

Comment 8

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

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

Comment 9

[Alexandru Michis [:malexandru]]

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=325373469&repo=autoland&lineNumber=12315

Comment 10

[Intermittent Failures Robot]

1 failures in 1450 pushes (0.001 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/bugdetails?bug=1610544&startday=2020-12-21&endday=2020-12-27&tree=all

Comment 11

[Intermittent Failures Robot]

1 failures in 2956 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/bugdetails?bug=1610544&startday=2021-01-04&endday=2021-01-10&tree=all

Comment 12

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

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