Filed by: archaeopteryx [at] coole-files.de https://treeherder.mozilla.org/logviewer.html#?job_id=149895467&repo=autoland https://queue.taskcluster.net/v1/task/D7ubSqn6QqKHtbWPO6cEcQ/runs/0/artifacts/public/logs/live_backing.log 16:33:45 INFO - 1843 INFO Should have RTP stats for track {6334c294-a25f-4858-8292-11db468a9737} 16:33:45 INFO - 1844 INFO RTP stats: {"id":"outbound_rtp_audio_0","timestamp":1512491624583.19,"type":"outbound-rtp","isRemote":false,"mediaType":"audio","nackCount":0,"remoteId":"","ssrc":"2118774836","bytesSent":0,"packetsSent":0} 16:33:45 INFO - 1845 INFO Track {6334c294-a25f-4858-8292-11db468a9737} has 0 outbound-rtp RTP packets. 16:33:45 INFO - 1846 INFO TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_twoAudioStreams.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts 16:33:45 INFO - Buffered messages finished 16:33:45 ERROR - 1847 INFO TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_peerConnection_twoAudioStreams.html | Error in test execution: Error: Timeout checking for stats for track {0bafd661-ff37-410b-9886-99a411346cd9} 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:751:31 ... promise callback*execute/<@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:749:14 ... execute@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:744:12 ... async*runTestWhenReady/<@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:372:41 ... promise callback*runTestWhenReady@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:372: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_peerConnection_twoAudioStreams.html:15:3 ... 16:33:45 INFO - execute/<@dom/media/tests/mochitest/head.js:755:14 16:33:45 INFO - Async*execute@dom/media/tests/mochitest/head.js:744:12 16:33:45 INFO - async*runTestWhenReady/<@dom/media/tests/mochitest/head.js:372:41 16:33:45 INFO - promise callback*runTestWhenReady@dom/media/tests/mochitest/head.js:372:10 16:33:45 INFO - runNetworkTest@dom/media/tests/mochitest/pc.js:2189:9 16:33:45 INFO - async*@dom/media/tests/mochitest/test_peerConnection_twoAudioStreams.html:15:3 16:33:45 INFO - 1848 INFO TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_twoAudioStreams.htm

Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=166434035&repo=mozilla-inbound&lineNumber=55277 10:34:57 INFO - 1852 INFO TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_twoAudioStreams.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts 10:34:57 INFO - 1853 INFO Checking for stats in {"outbound_rtp_audio_0":{"id":"outbound_rtp_audio_0","timestamp":1520418896530,"type":"outboundrtp","isRemote":false,"mediaType":"audio","nackCount":0,"remoteId":"","ssrc":"1540941905","bytesSent":0,"packetsSent":0},"Y1mD":{"id":"Y1mD","timestamp":1520418896530,"type":"candidatepair","bytesReceived":773,"bytesSent":791,"componentId":1,"lastPacketReceivedTimestamp":817703588,"lastPacketSentTimestamp":817703593,"localCandidateId":"9r6T","nominated":true,"priority":9115005270282338000,"readable":true,"remoteCandidateId":"3Srm","selected":true,"state":"succeeded","transportId":"0-1520418865310000 (id=4294967842 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_twoAudioStreams. aLevel=0","writable":true},"9r6T":{"id":"9r6T","timestamp":1520418896530,"type":"localcandidate","candidateType":"host","componentId":"0-1520418865310000 (id=4294967842 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_twoAudioStreams. aLevel=0","ipAddress":"10.145.17.57","mozLocalTransport":"udp","portNumber":59356,"transport":"udp"},"jRcB":{"id":"jRcB","timestamp":1520418896530,"type":"localcandidate","candidateType":"host","componentId":"0-1520418865310000 (id=4294967842 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_twoAudioStreams. aLevel=0","ipAddress":"2001:0:4137:9e76:141f:10e8:47b6:c49c","mozLocalTransport":"udp","portNumber":59355,"transport":"udp"},"NO4U":{"id":"NO4U","timestamp":1520418896530,"type":"localcandidate","candidateType":"host","componentId":"0-1520418865310000 (id=4294967842 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_twoAudioStreams. aLevel=0","ipAddress":"10.145.17.57","mozLocalTransport":"tcp","portNumber":51716,"transport":"tcp"},"2oR7":{"id":"2oR7","timestamp":1520418896530,"type":"localcandidate","candidateType":"host","componentId":"0-1520418865310000 (id=4294967842 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_twoAudioStreams. aLevel=0","ipAddress":"2001:0:4137:9e76:141f:10e8:47b6:c49c","mozLocalTransport":"tcp","portNumber":59869,"transport":"tcp"},"3Srm":{"id":"3Srm","timestamp":1520418896530,"type":"remotecandidate","candidateType":"host","componentId":"0-1520418865310000 (id=4294967842 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_twoAudioStreams. aLevel=0","ipAddress":"10.145.17.57","portNumber":59362,"transport":"udp"}} for audio track {9117e55d-1b2a-4574-85d8-ce6e339f33f2}, retry number 60 10:34:57 INFO - 1854 INFO Should have RTP stats for track {9117e55d-1b2a-4574-85d8-ce6e339f33f2} 10:34:57 INFO - 1855 INFO RTP stats: {"id":"outbound_rtp_audio_0","timestamp":1520418896530,"type":"outbound-rtp","isRemote":false,"mediaType":"audio","nackCount":0,"remoteId":"","ssrc":"1540941905","bytesSent":0,"packetsSent":0} 10:34:57 INFO - 1856 INFO Track {9117e55d-1b2a-4574-85d8-ce6e339f33f2} has 0 outbound-rtp RTP packets. 10:34:57 INFO - 1857 INFO TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_twoAudioStreams.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts 10:34:57 INFO - Buffered messages finished 10:34:57 ERROR - 1858 INFO TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_peerConnection_twoAudioStreams.html | Error in test execution: Error: Timeout checking for stats for track {44eb0606-83e7-493f-ae4c-8497367f948c} after at least30000ms waitForRtpFlow@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:1555:11 ... async*waitForMediaFlow/<@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:1607:58 ... waitForMediaFlow@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:1607: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 ... 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/test_peerConnection_twoAudioStreams.html:15:3 ... 10:34:57 INFO - execute/<@dom/media/tests/mochitest/head.js:835:14 10:34:57 INFO - Async*execute@dom/media/tests/mochitest/head.js:824:12 10:34:57 INFO - async*runTestWhenReady/<@dom/media/tests/mochitest/head.js:452:41 10:34:57 INFO - promise callback*runTestWhenReady@dom/media/tests/mochitest/head.js:452:10 10:34:57 INFO - runNetworkTest@dom/media/tests/mochitest/pc.js:2196:9 10:34:57 INFO - async*@dom/media/tests/mochitest/test_peerConnection_twoAudioStreams.html:15:3 10:34:57 INFO - 1859 INFO TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_twoAudioStreams.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts 10:34:57 INFO - 1860 INFO Closing peer connections 10:34:57 INFO - 1861 INFO Waiting for track {44eb0606-83e7-493f-ae4c-8497367f948c} (audio) to end. 10:34:57 INFO - 1862 INFO TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_twoAudioStreams.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts 10:34:57 INFO - 1863 INFO Waiting for track {2d79e4a6-8518-4ce8-a885-cc17e0e675bd} (audio) to end. 10:34:57 INFO - 1864 INFO TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_twoAudioStreams.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts 10:34:57 INFO - 1865 INFO TEST-PASS | dom/media/tests/mochitest/test_peerConnection_twoAudioStreams.html | iceConnectionState should not be undefined 10:34:57 INFO - 1866 INFO PeerConnectionWrapper (pcLocal): oniceconnectionstatechange fired, new state is: closed 10:34:57 INFO - 1867 INFO TEST-PASS | dom/media/tests/mochitest/test_peerConnection_twoAudioStreams.html | PeerConnectionWrapper (pcLocal): legal ICE state transition from connected to closed 10:34:57 INFO - GECKO(5612) | [4076:Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2768: mozilla::PeerConnectionImpl::CloseInt: Closing PeerConnectionImpl 9257e7963233da77; ending call 10:34:57 INFO - GECKO(5612) | [4076:Main Thread]: I/jsep [1520418865310000 (id=4294967842 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_twoAudioStreams.]: stable -> closed 10:34:57 INFO - GECKO(5612) | [4076:Socket Thread]: I/signaling [Socket Thread|MediaPipeline] MediaPipeline.cpp:651: 9257e7963233da77| Receive audio in mozilla::MediaPipeline::DetachTransport_s 10:34:57 INFO - GECKO(5612) | [4076:Socket Thread]: I/signaling [Socket Thread|MediaPipeline] MediaPipeline.cpp:651: 9257e7963233da77| Transmit audio[{56ba024b-64c6-4a73-86d9-e225dd005a3b}] in mozilla::MediaPipeline::DetachTransport_s 10:34:57 INFO - GECKO(5612) | [4076:Socket Thread]: I/signaling [Socket Thread|MediaPipeline] MediaPipeline.cpp:651: 9257e7963233da77| Receive audio in mozilla::MediaPipeline::DetachTransport_s 10:34:57 INFO - GECKO(5612) | [4076:Socket Thread]: I/signaling [Socket Thread|MediaPipeline] MediaPipeline.cpp:651: 9257e7963233da77| Transmit audio[{9117e55d-1b2a-4574-85d8-ce6e339f33f2}] in mozilla::MediaPipeline::DetachTransport_s 10:34:57 INFO - 1868 INFO PeerConnectionWrapper (pcLocal): "onsignalingstatechange" event fired 10:34:57 INFO - 1869 INFO TEST-PASS | dom/media/tests/mochitest/test_peerConnection_twoAudioStreams.html | signalingState is closed 10:34:57 INFO - 1870 INFO TEST-PASS | dom/media/tests/mochitest/test_peerConnection_twoAudioStreams.html | PeerConnectionWrapper (pcLocal): legal signaling state transition from stable to closed 10:34:57 INFO - 1871 INFO PeerConnectionWrapper (pcLocal): Closed connection. 10:34:57 INFO - 1872 INFO Waiting for track {6a9035f0-c498-437f-9cf2-169dd0e45b09} (audio) to end. 10:34:57 INFO - 1873 INFO TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_twoAudioStreams.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts 10:34:57 INFO - 1874 INFO Waiting for track {264979d3-5500-49f0-8418-1a77d72dffbc} (audio) to end. 10:34:57 INFO - 1875 INFO TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_twoAudioStreams.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts 10:34:57 INFO - 1876 INFO TEST-PASS | dom/media/tests/mochitest/test_peerConnection_twoAudioStreams.html | iceConnectionState should not be undefined 10:34:57 INFO - 1877 INFO PeerConnectionWrapper (pcRemote): oniceconnectionstatechange fired, new state is: closed 10:34:57 INFO - 1878 INFO TEST-PASS | dom/media/tests/mochitest/test_peerConnection_twoAudioStreams.html | PeerConnectionWrapper (pcRemote): legal ICE state transition from connected to closed 10:34:57 INFO - GECKO(5612) | [4076:Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2768: mozilla::PeerConnectionImpl::CloseInt: Closing PeerConnectionImpl f2c4b6de1dd91740; ending call 10:34:57 INFO - GECKO(5612) | [4076:Main Thread]: I/jsep [1520418865319000 (id=4294967842 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_twoAudioStreams.]: stable -> closed 10:34:57 INFO - GECKO(5612) | [4076:Socket Thread]: I/signaling [Socket Thread|MediaPipeline] MediaPipeline.cpp:651: f2c4b6de1dd91740| Receive audio in mozilla::MediaPipeline::DetachTransport_s 10:34:57 INFO - GECKO(5612) | [4076:Socket Thread]: I/signaling [Socket Thread|MediaPipeline] MediaPipeline.cpp:651: f2c4b6de1dd91740| Transmit audio[{9f6d0726-152c-4b0f-8688-dfe86af9139d}] in mozilla::MediaPipeline::DetachTransport_s 10:34:57 INFO - GECKO(5612) | [4076:Socket Thread]: I/signaling [Socket Thread|MediaPipeline] MediaPipeline.cpp:651: f2c4b6de1dd91740| Receive audio in mozilla::MediaPipeline::DetachTransport_s 10:34:57 INFO - GECKO(5612) | [4076:Socket Thread]: I/signaling [Socket Thread|MediaPipeline] MediaPipeline.cpp:651: f2c4b6de1dd91740| Transmit audio[{590850d4-08de-4e3e-b9ef-5a64e4cddcaf}] in mozilla::MediaPipeline::DetachTransport_s 10:34:57 INFO - 1879 INFO PeerConnectionWrapper (pcRemote): "onsignalingstatechange" event fired 10:34:57 INFO - 1880 INFO TEST-PASS | dom/media/tests/mochitest/test_peerConnection_twoAudioStreams.html | signalingState is closed 10:34:57 INFO - 1881 INFO TEST-PASS | dom/media/tests/mochitest/test_peerConnection_twoAudioStreams.html | PeerConnectionWrapper (pcRemote): legal signaling state transition from stable to closed 10:34:57 INFO - GECKO(5612) | [Parent 5612, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 10:34:57 INFO - 1882 INFO PeerConnectionWrapper (pcRemote): Closed connection. 10:34:57 INFO - 1883 INFO TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_twoAudioStreams.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts 10:34:57 INFO - GECKO(5612) | [4076:Main Thread]: I/signaling [main|MediaPipeline] MediaPipeline.cpp:629: Destroying MediaPipeline: 9257e7963233da77| Transmit audio[{56ba024b-64c6-4a73-86d9-e225dd005a3b}] 10:34:57 INFO - GECKO(5612) | [4076:Main Thread]: I/signaling [main|MediaPipeline] MediaPipeline.cpp:629: Destroying MediaPipeline: 9257e7963233da77| Transmit audio[{9117e55d-1b2a-4574-85d8-ce6e339f33f2}] 10:34:57 INFO - GECKO(5612) | [4076:Main Thread]: I/signaling [main|MediaPipeline] MediaPipeline.cpp:629: Destroying MediaPipeline: 9257e7963233da77| Receive audio 10:34:57 INFO - GECKO(5612) | [4076:Main Thread]: I/signaling [main|MediaPipeline] MediaPipeline.cpp:629: Destroying MediaPipeline: 9257e7963233da77| Receive audio 10:34:57 INFO - GECKO(5612) | [4076:Main Thread]: I/signaling [main|MediaPipeline] MediaPipeline.cpp:629: Destroying MediaPipeline: f2c4b6de1dd91740| Transmit audio[{9f6d0726-152c-4b0f-8688-dfe86af9139d}] 10:34:57 INFO - GECKO(5612) | [4076:Main Thread]: I/signaling [main|MediaPipeline] MediaPipeline.cpp:629: Destroying MediaPipeline: f2c4b6de1dd91740| Transmit audio[{590850d4-08de-4e3e-b9ef-5a64e4cddcaf}] 10:34:57 INFO - GECKO(5612) | [4076:Main Thread]: I/signaling [main|MediaPipeline] MediaPipeline.cpp:629: Destroying MediaPipeline: f2c4b6de1dd91740| Receive audio 10:34:57 INFO - GECKO(5612) | [4076:Main Thread]: I/signaling [main|MediaPipeline] MediaPipeline.cpp:629: Destroying MediaPipeline: f2c4b6de1dd91740| Receive audio 10:35:03 INFO - GECKO(5612) | Timecard created 1520418865.307000

This looks really similar to bug 1434983.

Fail reappeared on autoland. Log link: https://treeherder.mozilla.org/logviewer.html#?job_id=205862210&repo=autoland&lineNumber=39076