1445759 - Intermittent dom/media/tests/mochitest/identity/test_setIdentityProviderWithErrors.html | Error in test execution: Error: Element _local_{9fe35e77-5a58-487d-a472-58029135dc65} should progress currentTime

Status: RESOLVED INCOMPLETE

(Core :: Audio/Video: Playback, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: apavel [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=167985158&repo=autoland

https://queue.taskcluster.net/v1/task/Dn4uGtLKQ8aettDz4Kbqtw/runs/0/artifacts/public/logs/live_backing.log

17:58:22     INFO -  1349 INFO TEST-PASS | dom/media/tests/mochitest/identity/test_setIdentityProviderWithErrors.html | Element ended should be the inverse of the MediaStream's active state
17:58:22     INFO -  1350 INFO TEST-FAIL | dom/media/tests/mochitest/identity/test_setIdentityProviderWithErrors.html | The author of the test has indicated that flaky timeouts are expected.  Reason: WebRTC inherently depends on timeouts
17:58:22     INFO -  1351 INFO Found transceiver that should be receiving RTP: mid=sdparta_0 currentDirection=sendrecv kind=audio track-id={758f64d0-2368-48ab-b9b4-9faf81cdc948}
17:58:22     INFO -  1352 INFO Checking data flow for element: _remote_{758f64d0-2368-48ab-b9b4-9faf81cdc948}
17:58:22     INFO -  1353 INFO TEST-PASS | dom/media/tests/mochitest/identity/test_setIdentityProviderWithErrors.html | Element ended should be the inverse of the MediaStream's active state
17:58:22     INFO -  1354 INFO TEST-FAIL | dom/media/tests/mochitest/identity/test_setIdentityProviderWithErrors.html | The author of the test has indicated that flaky timeouts are expected.  Reason: WebRTC inherently depends on timeouts
17:58:22     INFO -  1355 INFO Found transceiver that should be receiving RTP: mid=sdparta_0 currentDirection=sendrecv kind=audio track-id={758f64d0-2368-48ab-b9b4-9faf81cdc948}
17:58:22     INFO -  1356 INFO waitForRtpFlow({758f64d0-2368-48ab-b9b4-9faf81cdc948})
17:58:22     INFO -  1357 INFO waitForRtpFlow({9fe35e77-5a58-487d-a472-58029135dc65})
17:58:22     INFO -  1358 INFO Element _local_{9fe35e77-5a58-487d-a472-58029135dc65} has enough data.
17:58:22     INFO -  1359 INFO Element _remote_{758f64d0-2368-48ab-b9b4-9faf81cdc948} has enough data.
17:58:22     INFO -  1360 INFO Checking for stats in {"inbound_rtp_audio_0":{"id":"inbound_rtp_audio_0","timestamp":1521050241918,"type":"inboundrtp","isRemote":false,"mediaType":"audio","nackCount":0,"ssrc":"3783408428","bytesReceived":203,"jitter":0,"packetsLost":0,"packetsReceived":1},"2ulW":{"id":"2ulW","timestamp":1521050241918,"type":"candidatepair","bytesReceived":1080,"bytesSent":1139,"componentId":1,"lastPacketReceivedTimestamp":1449079636,"lastPacketSentTimestamp":1449079644,"localCandidateId":"3uqO","nominated":true,"priority":9115005270282338000,"readable":true,"remoteCandidateId":"WzRf","selected":true,"state":"succeeded","transportId":"0-1521050241439000 (id=4294967335 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/identity/test_setIdentityProviderWit aLevel=0","writable":true},"3uqO":{"id":"3uqO","timestamp":1521050241918,"type":"localcandidate","candidateType":"host","componentId":"0-1521050241439000 (id=4294967335 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/identity/test_setIdentityProviderWit aLevel=0","ipAddress":"10.145.72.150","mozLocalTransport":"udp","portNumber":61342,"transport":"udp"},"QAsP":{"id":"QAsP","timestamp":1521050241918,"type":"localcandidate","candidateType":"host","componentId":"0-1521050241439000 (id=4294967335 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/identity/test_setIdentityProviderWit aLevel=0","ipAddress":"2001:0:4137:9e76:1c78:2c29:c91f:9c5b","mozLocalTransport":"udp","portNumber":61341,"transport":"udp"},"Yq/1":{"id":"Yq/1","timestamp":1521050241918,"type":"localcandidate","candidateType":"host","componentId":"0-1521050241439000 (id=4294967335 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/identity/test_setIdentityProviderWit aLevel=0","ipAddress":"10.145.72.150","mozLocalTransport":"tcp","portNumber":61793,"transport":"tcp"},"kBkd":{"id":"kBkd","timestamp":1521050241918,"type":"localcandidate","candidateType":"host","componentId":"0-1521050241439000 (id=4294967335 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/identity/test_setIdentityProviderWit aLevel=0","ipAddress":"2001:0:4137:9e76:1c78:2c29:c91f:9c5b","mozLocalTransport":"tcp","portNumber":57097,"transport":"tcp"},"WzRf":{"id":"WzRf","timestamp":1521050241918,"type":"remotecandidate","candidateType":"host","componentId":"0-1521050241439000 (id=4294967335 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/identity/test_setIdentityProviderWit aLevel=0","ipAddress":"10.145.72.150","portNumber":61346,"transport":"udp"}} for audio track {758f64d0-2368-48ab-b9b4-9faf81cdc948}, retry number 0
17:58:22     INFO -  1361 INFO Should have RTP stats for track {758f64d0-2368-48ab-b9b4-9faf81cdc948}
17:58:22     INFO -  1362 INFO RTP stats: {"id":"inbound_rtp_audio_0","timestamp":1521050241918,"type":"inbound-rtp","isRemote":false,"mediaType":"audio","nackCount":0,"ssrc":"3783408428","bytesReceived":203,"jitter":0,"packetsLost":0,"packetsReceived":1}
17:58:22     INFO -  1363 INFO Track {758f64d0-2368-48ab-b9b4-9faf81cdc948} has 1 inbound-rtp RTP packets.
17:58:22     INFO -  1364 INFO TEST-PASS | dom/media/tests/mochitest/identity/test_setIdentityProviderWithErrors.html | RTP flowing for audio track {758f64d0-2368-48ab-b9b4-9faf81cdc948}
17:58:22     INFO -  1365 INFO Checking for stats in {"outbound_rtp_audio_0":{"id":"outbound_rtp_audio_0","timestamp":1521050241924,"type":"outboundrtp","isRemote":false,"mediaType":"audio","nackCount":0,"remoteId":"","ssrc":"1936053193","bytesSent":232,"packetsSent":1},"2ulW":{"id":"2ulW","timestamp":1521050241924,"type":"candidatepair","bytesReceived":1080,"bytesSent":1139,"componentId":1,"lastPacketReceivedTimestamp":1449079636,"lastPacketSentTimestamp":1449079644,"localCandidateId":"3uqO","nominated":true,"priority":9115005270282338000,"readable":true,"remoteCandidateId":"WzRf","selected":true,"state":"succeeded","transportId":"0-1521050241439000 (id=4294967335 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/identity/test_setIdentityProviderWit aLevel=0","writable":true},"3uqO":{"id":"3uqO","timestamp":1521050241924,"type":"localcandidate","candidateType":"host","componentId":"0-1521050241439000 (id=4294967335 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/identity/test_setIdentityProviderWit aLevel=0","ipAddress":"10.145.72.150","mozLocalTransport":"udp","portNumber":61342,"transport":"udp"},"QAsP":{"id":"QAsP","timestamp":1521050241924,"type":"localcandidate","candidateType":"host","componentId":"0-1521050241439000 (id=4294967335 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/identity/test_setIdentityProviderWit aLevel=0","ipAddress":"2001:0:4137:9e76:1c78:2c29:c91f:9c5b","mozLocalTransport":"udp","portNumber":61341,"transport":"udp"},"Yq/1":{"id":"Yq/1","timestamp":1521050241924,"type":"localcandidate","candidateType":"host","componentId":"0-1521050241439000 (id=4294967335 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/identity/test_setIdentityProviderWit aLevel=0","ipAddress":"10.145.72.150","mozLocalTransport":"tcp","portNumber":61793,"transport":"tcp"},"kBkd":{"id":"kBkd","timestamp":1521050241924,"type":"localcandidate","candidateType":"host","componentId":"0-1521050241439000 (id=4294967335 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/identity/test_setIdentityProviderWit aLevel=0","ipAddress":"2001:0:4137:9e76:1c78:2c29:c91f:9c5b","mozLocalTransport":"tcp","portNumber":57097,"transport":"tcp"},"WzRf":{"id":"WzRf","timestamp":1521050241924,"type":"remotecandidate","candidateType":"host","componentId":"0-1521050241439000 (id=4294967335 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/identity/test_setIdentityProviderWit aLevel=0","ipAddress":"10.145.72.150","portNumber":61346,"transport":"udp"}} for audio track {9fe35e77-5a58-487d-a472-58029135dc65}, retry number 0
17:58:22     INFO -  1366 INFO Should have RTP stats for track {9fe35e77-5a58-487d-a472-58029135dc65}
17:58:22     INFO -  1367 INFO RTP stats: {"id":"outbound_rtp_audio_0","timestamp":1521050241924,"type":"outbound-rtp","isRemote":false,"mediaType":"audio","nackCount":0,"remoteId":"","ssrc":"1936053193","bytesSent":232,"packetsSent":1}
17:58:22     INFO -  1368 INFO Track {9fe35e77-5a58-487d-a472-58029135dc65} has 1 outbound-rtp RTP packets.
17:58:22     INFO -  1369 INFO TEST-PASS | dom/media/tests/mochitest/identity/test_setIdentityProviderWithErrors.html | RTP flowing for audio track {9fe35e77-5a58-487d-a472-58029135dc65}
17:58:22     INFO -  Buffered messages finished
17:58:22    ERROR -  1370 INFO TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/identity/test_setIdentityProviderWithErrors.html | Error in test execution: Error: Element _local_{9fe35e77-5a58-487d-a472-58029135dc65} should progress currentTime timeout/<@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:572:63 ... promise callback*timeout@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:572:26 ... waitForMediaElementFlow@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:1506:28 ... waitForMediaFlow/<@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:1601:46 ... waitForMediaFlow@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:1601:7 ... PC_LOCAL_WAIT_FOR_MEDIA_FLOW@http://mochi.test:8888/tests/dom/media/tests/mochitest/templates.js:374:12 ... execute/</<@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:831:31 ... promise callback*execute/<@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:829:14 ... execute@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:824:12 ... PeerConnectionTest.prototype.run@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:485:10 ... @http://mochi.test:8888/tests/dom/media/tests/mochitest/identity/test_setIdentityProviderWithErrors.html:49:3 ... runNetworkTest/<@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:2214:13 ... async*runTestWhenReady/<@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:452:41 ... promise callback*runTestWhenReady@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:452:10 ... runNetworkTest@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:2196:9 ... async*@http://mochi.test:8888/tests/dom/media/tests/mochitest/identity/test_setIdentityProviderWithErrors.html:16:1 ...
17:58:22     INFO -      execute/<@dom/media/tests/mochitest/head.js:835:14
17:58:22     INFO -      Async*execute@dom/media/tests/mochitest/head.js:824:12
17:58:22     INFO -      PeerConnectionTest.prototype.run@dom/media/tests/mochitest/pc.js:485:10
17:58:22     INFO -      @dom/media/tests/mochitest/identity/test_setIdentityProviderWithErrors.html:49:3
17:58:22     INFO -      runNetworkTest/<@dom/media/tests/mochitest/pc.js:2214:13
17:58:22     INFO -      async*runTestWhenReady/<@dom/media/tests/mochitest/head.js:452:41
17:58:22     INFO -      promise callback*runTestWhenReady@dom/media/tests/mochitest/head.js:452:10
17:58:22     INFO -      runNetworkTest@dom/media/tests/mochitest/pc.js:2196:9
17:58:22     INFO -      async*@dom/media/tests/mochitest/identity/test_setIdentityProviderWithErrors.html:16:1
17:58:22     INFO -  1371 INFO TEST-FAIL | dom/media/tests/mochitest/identity/test_setIdentityProviderWithErrors.html | The author of the test has indicated that flaky timeouts are expected.  Reason: WebRTC inherently depends on timeouts
17:58:22     INFO -  1372 INFO Closing peer connections
17:58:22     INFO -  1373 INFO Waiting for track {758f64d0-2368-48ab-b9b4-9faf81cdc948} (audio) to end.
17:58:22     INFO -  1374 INFO TEST-FAIL | dom/media/tests/mochitest/identity/test_setIdentityProviderWithErrors.html | The author of the test has indicated that flaky timeouts are expected.  Reason: WebRTC inherently depends on timeouts
17:58:22     INFO -  1375 INFO TEST-PASS | dom/media/tests/mochitest/identity/test_setIdentityProviderWithErrors.html | iceConnectionState should not be undefined
17:58:22     INFO -  1376 INFO PeerConnectionWrapper (pcLocal): oniceconnectionstatechange fired, new state is: closed
17:58:22     INFO -  1377 INFO TEST-PASS | dom/media/tests/mochitest/identity/test_setIdentityProviderWithErrors.html | PeerConnectionWrapper (pcLocal): legal ICE state transition from connected to closed

Comment 1

[Intermittent Failures Robot]

1 failures in 814 pushes (0.001 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://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1445759&startday=2018-03-12&endday=2018-03-18&tree=all

Comment 2

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Comment 3

[Arthur Iakab [arthur_iakab]]

Failed here https://treeherder.mozilla.org/#/jobs?repo=try&resultStatus=testfailed%2Cbusted%2Cexception%2Cusercancel%2Crunnable&selectedJob=203856917&revision=fe899aa0ca1d613a0faf9d2b62328cb355c5e494

Failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=203856917&repo=try&lineNumber=11852

Part of that log: 
17:57:29     INFO - TEST-PASS | dom/media/tests/mochitest/identity/test_setIdentityProviderWithErrors.html | RTP flowing for audio track {3ff51c63-aa75-40ef-8902-10d88b2f2b06} 
17:57:29     INFO - Buffered messages finished
17:57:29     INFO - TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/identity/test_setIdentityProviderWithErrors.html | Error in test execution: Error: Element _local_{3ff51c63-aa75-40ef-8902-10d88b2f2b06} should progress currentTime timeout/<@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:591:63 ...  
17:57:29     INFO -     execute/<@dom/media/tests/mochitest/head.js:854:14
17:57:29     INFO - TEST-FAIL | dom/media/tests/mochitest/identity/test_setIdentityProviderWithErrors.html | The author of the test has indicated that flaky timeouts are expected.  Reason: WebRTC inherently depends on timeouts 
17:57:29     INFO - Closing peer connections
17:57:29     INFO - Waiting for track {19fe0554-821b-40de-8cf0-f8bb503d6649} (audio) to end.
17:57:29     INFO - TEST-FAIL | dom/media/tests/mochitest/identity/test_setIdentityProviderWithErrors.html | The author of the test has indicated that flaky timeouts are expected.  Reason: WebRTC inherently depends on timeouts 
17:57:29     INFO - TEST-PASS | dom/media/tests/mochitest/identity/test_setIdentityProviderWithErrors.html | iceConnectionState should not be undefined

Comment 4

[Intermittent Failures Robot]

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

Repository breakdown:
* try: 1

Platform breakdown:
* windows10-64-qr: 1

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

Comment 5

[Intermittent Failures Robot]

1 failures in 3007 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=1445759&startday=2018-11-05&endday=2018-11-11&tree=all

Comment 6

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Comment 7

[Alexandru Michis [:malexandru]]

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

Comment 8

[Intermittent Failures Robot]

1 failures in 4331 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=1445759&startday=2019-11-25&endday=2019-12-01&tree=all

Comment 9

[Intermittent Failures Robot]

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

Repository breakdown:

• try: 1

Platform breakdown:

• windows10-64: 1

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

Comment 10

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

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