1422502 - Intermittent dom/media/tests/mochitest/test_dataChannel_basicAudioVideoNoBundle.html | Error in test execution: Error: Timeout checking for stats for track {88825e0d-cae6-42db-8d5f-f5efddc49023} after at least30000ms waitForRtpFlow@http://mochi.test:8888/

Status: RESOLVED INCOMPLETE

(Core :: WebRTC, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: philringnalda [at] gmail.com

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

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

Comment 1

[Intermittent Failures Robot]

1 failures in 792 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://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1422502&startday=2017-11-27&endday=2017-12-03&tree=all

Comment 2

[Intermittent Failures Robot]

1 failures in 889 pushes (0.001 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://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1422502&startday=2017-12-04&endday=2017-12-10&tree=all

Comment 3

[Intermittent Failures Robot]

1 failures in 590 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://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1422502&startday=2017-12-18&endday=2017-12-24&tree=all

Comment 4

[Firefox Bug Husbandry Bot]

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

Comment 5

[Andreea Pavel [:apavel]]

Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=158068050&repo=mozilla-inbound&lineNumber=31325

23:01:53     INFO -  1067 INFO TEST-FAIL | dom/media/tests/mochitest/test_dataChannel_basicAudioVideoNoBundle.html | The author of the test has indicated that flaky timeouts are expected.  Reason: WebRTC inherently depends on timeouts
23:01:53     INFO -  1068 INFO Checking for stats in {"outbound_rtcp_video_0":{"id":"outbound_rtcp_video_0","timestamp":1579748,"type":"inboundrtp","isRemote":true,"mediaType":"video","remoteId":"outbound_rtp_video_0","ssrc":"613762180","bytesReceived":0,"jitter":0,"packetsLost":0,"packetsReceived":0},"outbound_rtp_video_0":{"id":"outbound_rtp_video_0","timestamp":1516748513293.88,"type":"outboundrtp","bitrateMean":0,"bitrateStdDev":0,"firCount":0,"framerateMean":0,"framerateStdDev":0,"isRemote":false,"mediaType":"video","nackCount":0,"pliCount":0,"remoteId":"outbound_rtcp_video_0","ssrc":"613762180","bytesSent":0,"droppedFrames":0,"framesEncoded":0,"packetsSent":0},"50Gp":{"id":"50Gp","timestamp":1516748513293.88,"type":"candidatepair","bytesReceived":771,"bytesSent":787,"lastPacketReceivedTimestamp":1442287966,"lastPacketSentTimestamp":1442287971,"localCandidateId":"f6l0","nominated":true,"priority":9115005270282338000,"readable":true,"remoteCandidateId":"1k9m","selected":true,"state":"succeeded","transportId":"0-1516748482485000 (id=4294967318 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_dataChannel_basicAudioVideoNoBu aLevel=0","writable":true},"f6l0":{"id":"f6l0","timestamp":1516748513293.88,"type":"localcandidate","candidateType":"host","componentId":"0-1516748482485000 (id=4294967318 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_dataChannel_basicAudioVideoNoBu aLevel=0","ipAddress":"10.144.38.156","mozLocalTransport":"udp","portNumber":54350,"transport":"udp"},"1WAE":{"id":"1WAE","timestamp":1516748513293.88,"type":"localcandidate","candidateType":"host","componentId":"0-1516748482485000 (id=4294967318 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_dataChannel_basicAudioVideoNoBu aLevel=0","ipAddress":"2001:0:9d38:953c:1457:3408:cbd9:cbe1","mozLocalTransport":"udp","portNumber":54349,"transport":"udp"},"H/nE":{"id":"H/nE","timestamp":1516748513293.88,"type":"localcandidate","candidateType":"host","componentId":"0-1516748482485000 (id=4294967318 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_dataChannel_basicAudioVideoNoBu aLevel=0","ipAddress":"10.144.38.156","mozLocalTransport":"tcp","portNumber":62588,"transport":"tcp"},"Acy1":{"id":"Acy1","timestamp":1516748513293.88,"type":"localcandidate","candidateType":"host","componentId":"0-1516748482485000 (id=4294967318 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_dataChannel_basicAudioVideoNoBu aLevel=0","ipAddress":"2001:0:9d38:953c:1457:3408:cbd9:cbe1","mozLocalTransport":"tcp","portNumber":56155,"transport":"tcp"},"1k9m":{"id":"1k9m","timestamp":1516748513293.88,"type":"remotecandidate","candidateType":"host","componentId":"0-1516748482485000 (id=4294967318 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_dataChannel_basicAudioVideoNoBu aLevel=0","ipAddress":"10.144.38.156","portNumber":54357,"transport":"udp"}} for video track {69e4dbae-8269-41eb-a6ae-0515cb336c05}, retry number 60
23:01:53     INFO -  1069 INFO Should have RTP stats for track {69e4dbae-8269-41eb-a6ae-0515cb336c05}
23:01:53     INFO -  1070 INFO RTP stats: {"id":"outbound_rtp_video_0","timestamp":1516748513293.88,"type":"outbound-rtp","bitrateMean":0,"bitrateStdDev":0,"firCount":0,"framerateMean":0,"framerateStdDev":0,"isRemote":false,"mediaType":"video","nackCount":0,"pliCount":0,"remoteId":"outbound_rtcp_video_0","ssrc":"613762180","bytesSent":0,"droppedFrames":0,"framesEncoded":0,"packetsSent":0}
23:01:53     INFO -  1071 INFO Track {69e4dbae-8269-41eb-a6ae-0515cb336c05} has 0 outbound-rtp RTP packets.
23:01:53     INFO -  1072 INFO TEST-FAIL | dom/media/tests/mochitest/test_dataChannel_basicAudioVideoNoBundle.html | The author of the test has indicated that flaky timeouts are expected.  Reason: WebRTC inherently depends on timeouts
23:01:53     INFO -  Buffered messages finished
23:01:53    ERROR -  1073 INFO TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_dataChannel_basicAudioVideoNoBundle.html | Error in test execution: Error: Timeout checking for stats for track {af63b518-af63-4494-b40f-55e864644f77} after at least30000ms waitForRtpFlow@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:1548:11 ... async*waitForMediaFlow/<@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:1600:58 ... waitForMediaFlow@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:1600: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:827:31 ... promise callback*execute/<@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:825:14 ... execute@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:820:12 ... async*runTestWhenReady/<@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:448:41 ... promise callback*runTestWhenReady@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:448:10 ... runNetworkTest@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:2189:9 ... async*@http://mochi.test:8888/tests/dom/media/tests/mochitest/test_dataChannel_basicAudioVideoNoBundle.html:15:1 ...
23:01:53     INFO -      execute/<@dom/media/tests/mochitest/head.js:831:14
23:01:53     INFO -      Async*execute@dom/media/tests/mochitest/head.js:820:12
23:01:53     INFO -      async*runTestWhenReady/<@dom/media/tests/mochitest/head.js:448:41
23:01:53     INFO -      promise callback*runTestWhenReady@dom/media/tests/mochitest/head.js:448:10
23:01:53     INFO -      runNetworkTest@dom/media/tests/mochitest/pc.js:2189:9
23:01:53     INFO -      async*@dom/media/tests/mochitest/test_dataChannel_basicAudioVideoNoBundle.html:15:1
23:01:53     INFO -  1074 INFO closeDataChannels called with index: 0
23:01:53     INFO -  1075 INFO TEST-FAIL | dom/media/tests/mochitest/test_dataChannel_basicAudioVideoNoBundle.html | The author of the test has indicated that flaky timeouts are expected.  Reason: WebRTC inherently depends on timeouts
23:01:53     INFO -  1076 INFO DataChannelWrapper (pcRemote_channel_0): Closing channel
23:01:53     INFO -  GECKO(6024) | [9168:Main Thread]: D/DataChannel Connection 000001B181B83200/Channel 000001B18CF57280: Closing stream 1
23:01:53     INFO -  GECKO(6024) | [9168:Main Thread]: D/DataChannel Connection 000001B181B83200: Resetting outgoing stream 1
23:01:53     INFO -  GECKO(6024) | [9168:Main Thread]: D/DataChannel Connection 000001B181B83200: Sending outgoing stream reset for 1 streams
23:01:53     INFO -  1077 INFO TEST-FAIL | dom/media/tests/mochitest/test_dataChannel_basicAudioVideoNoBundle.html | The author of the test has indicated that flaky timeouts are expected.  Reason: WebRTC inherently depends on timeouts
23:01:53     INFO -  GECKO(6024) | [9168:Socket Thread]: D/DataChannel Incoming: Channel 1  closed, state 1
23:01:53     INFO -  GECKO(6024) | [9168:Socket Thread]: D/DataChannel Connection 000001B181B80600: Resetting outgoing stream 1
23:01:53     INFO -  GECKO(6024) | [9168:Socket Thread]: D/DataChannel Disconnected DataChannel 000001B18BCC8700 from connection 000001B181B80600
23:01:53     INFO -  GECKO(6024) | [9168:Socket Thread]: D/DataChannel Destroying Data channel 1
23:01:53     INFO -  GECKO(6024) | [9168:Socket Thread]: D/DataChannel Sending 1 pending resets
23:01:53     INFO -  GECKO(6024) | [9168:Socket Thread]: D/DataChannel Connection 000001B181B80600: Sending outgoing stream reset for 1 streams
23:01:53     INFO -  GECKO(6024) | [9168:Main Thread]: D/DataChannel 000001B18E0E15C0(000001B18BCC8700): nsDOMDataChannel::OnChannelClosed - Dispatching
23:01:53     INFO -  1078 INFO DataChannelWrapper (pcLocal_channel_0): "onclose" event fired
23:01:53     INFO -  1079 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideoNoBundle.html | /tests/dom/media/tests/mochitest/test_dataChannel_basicAudioVideoNoBundle.html channel 0 closed
23:01:53     INFO -  GECKO(6024) | [9168:Socket Thread]: D/DataChannel Incoming: Channel 1  closed, state 2
23:01:53     INFO -  GECKO(6024) | [9168:Socket Thread]: D/DataChannel Disconnected DataChannel 000001B18CF57280 from connection 000001B181B83200
23:01:53     INFO -  GECKO(6024) | [9168:Socket Thread]: D/DataChannel Destroying Data channel 1
23:01:53     INFO -  GECKO(6024) | [9168:Main Thread]: D/DataChannel 000001B18E00D700(000001B18CF57280): nsDOMDataChannel::OnChannelClosed - Dispatching
23:01:53     INFO -  1080 INFO DataChannelWrapper (pcRemote_channel_0): "onclose" event fired
23:01:53     INFO -  1081 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideoNoBundle.html | /tests/dom/media/tests/mochitest/test_dataChannel_basicAudioVideoNoBundle.html channel 0 closed
23:01:53     INFO -  1082 INFO Closing peer connections
23:01:53     INFO -  1083 INFO Waiting for track {af63b518-af63-4494-b40f-55e864644f77} (audio) to end.

Comment 6

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-inbound: 2

Platform breakdown:
* windows10-64-qr: 1
* linux32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1422502&startday=2018-01-22&endday=2018-01-28&tree=all

Comment 7

[Firefox Bug Husbandry Bot]

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