1474610 - Intermittent dom/media/tests/mochitest/test_peerConnection_addSecondAudioStream.html | Error in test execution: Error: Element _local_{d497932f-7e95-4a1c-8ada-149bc2aa06d9} should progress currentTime timeout

Status: RESOLVED INCOMPLETE

(Core :: WebRTC, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: apavel [at] mozilla.com

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

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

11:40:42     INFO -  1215 INFO TEST-PASS | dom/media/tests/mochitest/test_peerConnection_addSecondAudioStream.html | RTP flowing for audio track {883f47db-6557-402c-89fe-b61f9d8161be}
11:40:42     INFO -  1216 INFO Checking for stats in {"outbound_rtp_audio_0":{"id":"outbound_rtp_audio_0","timestamp":1531222782479,"type":"outboundrtp","isRemote":false,"mediaType":"audio","nackCount":0,"remoteId":"","ssrc":"431311620","bytesSent":2680,"packetsSent":20},"RIO9":{"id":"RIO9","timestamp":1531222782479,"type":"candidatepair","bytesReceived":4047,"bytesSent":3775,"componentId":1,"lastPacketReceivedTimestamp":18446744072446270000,"lastPacketSentTimestamp":18446744072446270000,"localCandidateId":"nDMB","nominated":true,"priority":9115005270282338000,"readable":true,"remoteCandidateId":"5XCP","selected":true,"state":"succeeded","transportId":"0-1531222782097000 (id=4294967452 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_addSecondAudioSt aLevel=0","writable":true},"+cBi":{"id":"+cBi","timestamp":1531222782479,"type":"candidatepair","bytesReceived":0,"bytesSent":0,"componentId":1,"lastPacketReceivedTimestamp":0,"lastPacketSentTimestamp":0,"localCandidateId":"cXUO","nominated":false,"priority":9114723795305497000,"readable":true,"remoteCandidateId":"z7Uf","selected":false,"state":"inprogress","transportId":"0-1531222782097000 (id=4294967452 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_addSecondAudioSt aLevel=0","writable":true},"nDMB":{"id":"nDMB","timestamp":1531222782479,"type":"localcandidate","candidateType":"host","componentId":"0-1531222782097000 (id=4294967452 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_addSecondAudioSt aLevel=0","ipAddress":"10.143.47.20","mozLocalTransport":"udp","portNumber":58546,"transport":"udp"},"cXUO":{"id":"cXUO","timestamp":1531222782479,"type":"localcandidate","candidateType":"host","componentId":"0-1531222782097000 (id=4294967452 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_addSecondAudioSt aLevel=0","ipAddress":"2001:0:9d38:90d7:307d:314e:ed6f:c3df","mozLocalTransport":"udp","portNumber":58545,"transport":"udp"},"V6GY":{"id":"V6GY","timestamp":1531222782479,"type":"localcandidate","candidateType":"host","componentId":"0-1531222782097000 (id=4294967452 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_addSecondAudioSt aLevel=0","ipAddress":"10.143.47.20","mozLocalTransport":"tcp","portNumber":51607,"transport":"tcp"},"Swa4":{"id":"Swa4","timestamp":1531222782479,"type":"localcandidate","candidateType":"host","componentId":"0-1531222782097000 (id=4294967452 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_addSecondAudioSt aLevel=0","ipAddress":"2001:0:9d38:90d7:307d:314e:ed6f:c3df","mozLocalTransport":"tcp","portNumber":51203,"transport":"tcp"},"5XCP":{"id":"5XCP","timestamp":1531222782479,"type":"remotecandidate","candidateType":"host","componentId":"0-1531222782097000 (id=4294967452 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_addSecondAudioSt aLevel=0","ipAddress":"10.143.47.20","portNumber":58542,"transport":"udp"},"z7Uf":{"id":"z7Uf","timestamp":1531222782479,"type":"remotecandidate","candidateType":"host","componentId":"0-1531222782097000 (id=4294967452 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_addSecondAudioSt aLevel=0","ipAddress":"2001:0:9d38:90d7:307d:314e:ed6f:c3df","portNumber":58541,"transport":"udp"},"7KQZ":{"id":"7KQZ","timestamp":1531222782479,"type":"remotecandidate","candidateType":"host","componentId":"0-1531222782097000 (id=4294967452 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_addSecondAudioSt aLevel=0","ipAddress":"10.143.47.20","portNumber":9,"transport":"tcp"},"s31B":{"id":"s31B","timestamp":1531222782479,"type":"remotecandidate","candidateType":"host","componentId":"0-1531222782097000 (id=4294967452 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_addSecondAudioSt aLevel=0","ipAddress":"2001:0:9d38:90d7:307d:314e:ed6f:c3df","portNumber":9,"transport":"tcp"}} for audio track {d497932f-7e95-4a1c-8ada-149bc2aa06d9}, retry number 0
11:40:42     INFO -  1217 INFO Should have RTP stats for track {d497932f-7e95-4a1c-8ada-149bc2aa06d9}
11:40:42     INFO -  1218 INFO RTP stats: {"id":"outbound_rtp_audio_0","timestamp":1531222782479,"type":"outbound-rtp","isRemote":false,"mediaType":"audio","nackCount":0,"remoteId":"","ssrc":"431311620","bytesSent":2680,"packetsSent":20}
11:40:42     INFO -  1219 INFO Track {d497932f-7e95-4a1c-8ada-149bc2aa06d9} has 20 outbound-rtp RTP packets.
11:40:42     INFO -  1220 INFO TEST-PASS | dom/media/tests/mochitest/test_peerConnection_addSecondAudioStream.html | RTP flowing for audio track {d497932f-7e95-4a1c-8ada-149bc2aa06d9}
11:40:42     INFO -  Buffered messages finished
11:40:42    ERROR -  1221 INFO TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_peerConnection_addSecondAudioStream.html | Error in test execution: Error: Element _local_{d497932f-7e95-4a1c-8ada-149bc2aa06d9} should progress currentTime timeout/<@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:596:63 ... promise callback*timeout@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:596: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_REMOTE_WAIT_FOR_MEDIA_FLOW@http://mochi.test:8888/tests/dom/media/tests/mochitest/templates.js:378:12 ... execute/</<@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:855:31 ... promise callback*execute/<@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:853:14 ... execute@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:848: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/test_peerConnection_addSecondAudioStream.html:40:5 ... 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:476:41 ... promise callback*runTestWhenReady@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:476: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/test_peerConnection_addSecondAudioStream.html:14:3 ...
11:40:42     INFO -      execute/<@dom/media/tests/mochitest/head.js:859:14
11:40:42     INFO -      promise callback*execute@dom/media/tests/mochitest/head.js:848:12
11:40:42     INFO -      PeerConnectionTest.prototype.run@dom/media/tests/mochitest/pc.js:485:10
11:40:42     INFO -      @dom/media/tests/mochitest/test_peerConnection_addSecondAudioStream.html:40:5
11:40:42     INFO -      runNetworkTest/<@dom/media/tests/mochitest/pc.js:2214:13
11:40:42     INFO -      async*runTestWhenReady/<@dom/media/tests/mochitest/head.js:476:41
11:40:42     INFO -      promise callback*runTestWhenReady@dom/media/tests/mochitest/head.js:476:10
11:40:42     INFO -      runNetworkTest@dom/media/tests/mochitest/pc.js:2196:9
11:40:42     INFO -      async*@dom/media/tests/mochitest/test_peerConnection_addSecondAudioStream.html:14:3
11:40:42     INFO -  1222 INFO TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_addSecondAudioStream.html | The author of the test has indicated that flaky timeouts are expected.  Reason: WebRTC inherently depends on timeouts
11:40:42     INFO -  1223 INFO Closing peer connections
11:40:42     INFO -  1224 INFO Waiting for track {fba4de6c-7296-47b0-b5a6-3c5c58497166} (audio) to end.
11:40:42     INFO -  1225 INFO TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_addSecondAudioStream.html | The author of the test has indicated that flaky timeouts are expected.  Reason: WebRTC inherently depends on timeouts
11:40:42     INFO -  1226 INFO TEST-PASS | dom/media/tests/mochitest/test_peerConnection_addSecondAudioStream.html | iceConnectionState should not be undefined

Comment 1

[Joel Maher ( :jmaher ) (UTC -8)]

unable to reproduce using test-verify:
https://treeherder.mozilla.org/#/jobs?repo=autoland&filter-searchStr=win%20pgo%20tv-bf&tochange=56b9739927e4220370015efaa32cadd831c2c903&fromchange=92fc73895c631def825b13f69b4eb3ca3dba7022

Comment 2

[Intermittent Failures Robot]

1 failures in 623 pushes (0.002 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=1474610&startday=2018-07-09&endday=2018-07-15&tree=trunk

Comment 3

[Firefox Bug Husbandry Bot]

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

Comment 4

[Cosmin Sabou [:CosminS]]

https://treeherder.mozilla.org/logviewer.html#?job_id=197247641&repo=mozilla-inbound&lineNumber=15330

Comment 5

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-inbound: 1

Platform breakdown:
* windows10-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1474610&startday=2018-09-03&endday=2018-09-09&tree=all

Comment 6

[Firefox Bug Husbandry Bot]

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

Comment 7

[Andreea Pavel [:apavel]]

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

23:15:31     INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_addSecondAudioStream.html | RTP flowing for audio track {adc14748-74ba-4fdf-8c93-e52975f4b87e} 
23:15:31     INFO - Checking for stats in {"outbound_rtp_audio_0":{"id":"outbound_rtp_audio_0","timestamp":1542669271056,"type":"outboundrtp","isRemote":false,"kind":"audio","mediaType":"audio","nackCount":0,"remoteId":"","ssrc":2079902680,"bytesSent":1999,"packetsSent":19}} for audio track {e0e12cb7-06b3-4674-bfa7-f64573b69b20}, retry number 0
23:15:31     INFO - Should have RTP stats for track {e0e12cb7-06b3-4674-bfa7-f64573b69b20}
23:15:31     INFO - RTP stats: {"id":"outbound_rtp_audio_0","timestamp":1542669271056,"type":"outbound-rtp","isRemote":false,"kind":"audio","mediaType":"audio","nackCount":0,"remoteId":"","ssrc":2079902680,"bytesSent":1999,"packetsSent":19,"_isRemote":false}
23:15:31     INFO - Track {e0e12cb7-06b3-4674-bfa7-f64573b69b20} has 19 outbound-rtp RTP packets.
23:15:31     INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_addSecondAudioStream.html | RTP flowing for audio track {e0e12cb7-06b3-4674-bfa7-f64573b69b20} 
23:15:31     INFO - Buffered messages finished
23:15:31     INFO - TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_peerConnection_addSecondAudioStream.html | Error in test execution: Error: Element _local_{e0e12cb7-06b3-4674-bfa7-f64573b69b20} should progress currentTime timeout/<@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:590:63 ... promise callback*timeout@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:590:37 ... waitForMediaElementFlow@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:1507:28 ... waitForMediaFlow/<@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:1602:46 ... waitForMediaFlow@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:1602:7 ... PC_REMOTE_WAIT_FOR_MEDIA_FLOW@http://mochi.test:8888/tests/dom/media/tests/mochitest/templates.js:378:12 ... execute/</<@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:849:31 ... promise callback*execute/<@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:847:14 ... execute@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:842:12 ... PeerConnectionTest.prototype.run@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:486:10 ... @http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_addSecondAudioStream.html:40:5 ... runNetworkTest/<@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:2211:13 ... async*runTestWhenReady/<@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:470:41 ... promise callback*runTestWhenReady@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:470:10 ... runNetworkTest@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:2193:9 ... async*@http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_addSecondAudioStream.html:14:3 ...  
23:15:31     INFO -     SimpleTest.ok@SimpleTest/SimpleTest.js:275:7
23:15:31     INFO -     execute/<@dom/media/tests/mochitest/head.js:853:14
23:15:31     INFO -     promise callback*execute@dom/media/tests/mochitest/head.js:852:8
23:15:31     INFO -     PeerConnectionTest.prototype.run@dom/media/tests/mochitest/pc.js:486:10
23:15:31     INFO -     @dom/media/tests/mochitest/test_peerConnection_addSecondAudioStream.html:40:5
23:15:31     INFO -     runNetworkTest/<@dom/media/tests/mochitest/pc.js:2211:13
23:15:31     INFO -     async*runTestWhenReady/<@dom/media/tests/mochitest/head.js:470:41
23:15:31     INFO -     promise callback*runTestWhenReady@dom/media/tests/mochitest/head.js:470:10
23:15:31     INFO -     runNetworkTest@dom/media/tests/mochitest/pc.js:2193:9
23:15:31     INFO -     async*@dom/media/tests/mochitest/test_peerConnection_addSecondAudioStream.html:14:3
23:15:31     INFO - TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_addSecondAudioStream.html | The author of the test has indicated that flaky timeouts are expected.  Reason: WebRTC inherently depends on timeouts

Comment 8

[Intermittent Failures Robot]

1 failures in 2387 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=1474610&startday=2018-11-19&endday=2018-11-25&tree=all

Comment 9

[Firefox Bug Husbandry Bot]

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