Closed Bug 1600209 Opened 6 years ago Closed 5 years ago

Intermittent mochitest/test_peerConnection_noTrickleOffer.html | Error in test execution: Error: Element _local_{28e917c7-7827-48be-a57e-8fee1a5032b6} should progress currentTime timeout/<@https://*/mochitest/head.js:652:42 ... promise callback*timeout@ht

Categories

(Core :: WebRTC, defect, P5)

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

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


[task 2019-11-29T00:20:15.406Z] 00:20:15 INFO - TEST-START | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html
[task 2019-11-29T00:20:15.449Z] 00:20:15 INFO - GECKO(2908) | [Parent 7716, Main Thread] WARNING: we only accept nsIURI interface type, patch welcome: file z:/build/build/src/dom/ipc/PropertyBagUtils.cpp, line 112
[task 2019-11-29T00:20:15.449Z] 00:20:15 INFO - GECKO(2908) | --DOCSHELL 000001DACBE84000 == 3 [pid = 1764] [id = {4827ecc3-6656-4558-a87d-1ab2485a1773}] [url = about:blank]
[task 2019-11-29T00:20:15.459Z] 00:20:15 INFO - GECKO(2908) | ++DOMWINDOW == 10 (000001DAD09CC400) [pid = 1764] [serial = 428] [outer = 000001DACBA4EC40]
[task 2019-11-29T00:20:15.526Z] 00:20:15 INFO - GECKO(2908) | ++DOCSHELL 000001DACBE84000 == 4 [pid = 1764] [id = {dd93a546-717f-450e-8309-28b4f9ecfa2d}]
[task 2019-11-29T00:20:15.526Z] 00:20:15 INFO - GECKO(2908) | ++DOMWINDOW == 11 (000001DACE8232E0) [pid = 1764] [serial = 429] [outer = 0000000000000000]
[task 2019-11-29T00:20:15.545Z] 00:20:15 INFO - GECKO(2908) | ++DOMWINDOW == 12 (000001DAD0ABAC00) [pid = 1764] [serial = 430] [outer = 000001DACE8232E0]
[task 2019-11-29T00:20:15.566Z] 00:20:15 INFO - GECKO(2908) | TEST DEVICES: No test device found in media.audio_loopback_dev, using fake audio streams.
[task 2019-11-29T00:20:15.566Z] 00:20:15 INFO - GECKO(2908) | TEST DEVICES: No test device found in media.video_loopback_dev, using fake video streams.
[task 2019-11-29T00:20:15.651Z] 00:20:15 INFO - GECKO(2908) | Timecard created 1574986814.574000
[task 2019-11-29T00:20:15.651Z] 00:20:15 INFO - GECKO(2908) | Timestamp | Delta | Event | File | Function
[task 2019-11-29T00:20:15.651Z] 00:20:15 INFO - GECKO(2908) | ======================================================================================================================
[task 2019-11-29T00:20:15.653Z] 00:20:15 INFO - GECKO(2908) | 0.000000 | 0.000000 | Constructor Completed | PeerConnectionImpl.cpp:336 | PeerConnectionImpl
[task 2019-11-29T00:20:15.653Z] 00:20:15 INFO - GECKO(2908) | 0.002000 | 0.002000 | Initializing PC Ctx | PeerConnectionImpl.cpp:462 | Initialize
[task 2019-11-29T00:20:15.653Z] 00:20:15 INFO - GECKO(2908) | 0.107000 | 0.105000 | Create Offer | PeerConnectionImpl.cpp:1258 | CreateOffer
[task 2019-11-29T00:20:15.655Z] 00:20:15 INFO - GECKO(2908) | 0.110000 | 0.003000 | Set Local Description | PeerConnectionImpl.cpp:1319 | SetLocalDescription
[task 2019-11-29T00:20:15.655Z] 00:20:15 INFO - GECKO(2908) | 0.163000 | 0.053000 | Ice gathering state: gathering | PeerConnectionImpl.cpp:2544 | IceGatheringStateChange
[task 2019-11-29T00:20:15.655Z] 00:20:15 INFO - GECKO(2908) | 0.190000 | 0.027000 | Ice gathering state: complete | PeerConnectionImpl.cpp:2547 | IceGatheringStateChange
[task 2019-11-29T00:20:15.655Z] 00:20:15 INFO - GECKO(2908) | 0.199000 | 0.009000 | Set Remote Description | PeerConnectionImpl.cpp:1407 | SetRemoteDescription
[task 2019-11-29T00:20:15.655Z] 00:20:15 INFO - GECKO(2908) | 0.281000 | 0.082000 | Ice state: checking | PeerConnectionImpl.cpp:2444 | IceConnectionStateChange
[task 2019-11-29T00:20:15.660Z] 00:20:15 INFO - GECKO(2908) | 0.357000 | 0.076000 | Ice state: connected | PeerConnectionImpl.cpp:2447 | IceConnectionStateChange
[task 2019-11-29T00:20:15.662Z] 00:20:15 INFO - GECKO(2908) | 1.074000 | 0.717000 | Destructor Invoked | PeerConnectionImpl.cpp:345 | ~PeerConnectionImpl
[task 2019-11-29T00:20:15.664Z] 00:20:15 INFO - GECKO(2908) | [Child 1764: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:370: ~PeerConnectionImpl: PeerConnectionImpl destructor invoked for a6b6ebb773bc7fdb
[task 2019-11-29T00:20:15.666Z] 00:20:15 INFO - GECKO(2908) | Timecard created 1574986814.579000
[task 2019-11-29T00:20:15.666Z] 00:20:15 INFO - GECKO(2908) | Timestamp | Delta | Event | File | Function
[task 2019-11-29T00:20:15.668Z] 00:20:15 INFO - GECKO(2908) | ======================================================================================================================
[task 2019-11-29T00:20:15.670Z] 00:20:15 INFO - GECKO(2908) | 0.000000 | 0.000000 | Constructor Completed | PeerConnectionImpl.cpp:336 | PeerConnectionImpl
[task 2019-11-29T00:20:15.672Z] 00:20:15 INFO - GECKO(2908) | 0.000000 | 0.000000 | Initializing PC Ctx | PeerConnectionImpl.cpp:462 | Initialize
[task 2019-11-29T00:20:15.672Z] 00:20:15 INFO - GECKO(2908) | 0.109000 | 0.109000 | Set Remote Description | PeerConnectionImpl.cpp:1407 | SetRemoteDescription
[task 2019-11-29T00:20:15.674Z] 00:20:15 INFO - GECKO(2908) | 0.137000 | 0.028000 | Create Answer | PeerConnectionImpl.cpp:1285 | CreateAnswer
[task 2019-11-29T00:20:15.676Z] 00:20:15 INFO - GECKO(2908) | 0.140000 | 0.003000 | Set Local Description | PeerConnectionImpl.cpp:1319 | SetLocalDescription
[task 2019-11-29T00:20:15.676Z] 00:20:15 INFO - GECKO(2908) | 0.159000 | 0.019000 | Ice gathering state: gathering | PeerConnectionImpl.cpp:2544 | IceGatheringStateChange
[task 2019-11-29T00:20:15.678Z] 00:20:15 INFO - GECKO(2908) | 0.168000 | 0.009000 | Add Ice Candidate | PeerConnectionImpl.cpp:1545 | AddIceCandidate
[task 2019-11-29T00:20:15.678Z] 00:20:15 INFO - GECKO(2908) | 0.177000 | 0.009000 | Add Ice Candidate | PeerConnectionImpl.cpp:1545 | AddIceCandidate
[task 2019-11-29T00:20:15.678Z] 00:20:15 INFO - GECKO(2908) | 0.180000 | 0.003000 | Add Ice Candidate | PeerConnectionImpl.cpp:1545 | AddIceCandidate
[task 2019-11-29T00:20:15.678Z] 00:20:15 INFO - GECKO(2908) | 0.182000 | 0.002000 | Add Ice Candidate | PeerConnectionImpl.cpp:1545 | AddIceCandidate
[task 2019-11-29T00:20:15.678Z] 00:20:15 INFO - GECKO(2908) | 0.184000 | 0.002000 | Add Ice Candidate | PeerConnectionImpl.cpp:1545 | AddIceCandidate
[task 2019-11-29T00:20:15.678Z] 00:20:15 INFO - GECKO(2908) | 0.189000 | 0.005000 | Ice gathering state: complete | PeerConnectionImpl.cpp:2547 | IceGatheringStateChange
[task 2019-11-29T00:20:15.679Z] 00:20:15 INFO - GECKO(2908) | 0.237000 | 0.048000 | Ice state: checking | PeerConnectionImpl.cpp:2444 | IceConnectionStateChange
[task 2019-11-29T00:20:15.681Z] 00:20:15 INFO - GECKO(2908) | 0.352000 | 0.115000 | Ice state: connected | PeerConnectionImpl.cpp:2447 | IceConnectionStateChange
[task 2019-11-29T00:20:15.681Z] 00:20:15 INFO - GECKO(2908) | 1.075000 | 0.723000 | Destructor Invoked | PeerConnectionImpl.cpp:345 | ~PeerConnectionImpl
[task 2019-11-29T00:20:15.681Z] 00:20:15 INFO - GECKO(2908) | [Child 1764: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:370: ~PeerConnectionImpl: PeerConnectionImpl destructor invoked for ea942facb0a820b7
[task 2019-11-29T00:20:15.761Z] 00:20:15 INFO - GECKO(2908) | [Child 1764, Main Thread] WARNING: Wrong inner/outer window combination!: file z:/build/build/src/dom/base/Document.cpp, line 6851
[task 2019-11-29T00:20:15.761Z] 00:20:15 INFO - GECKO(2908) | [Child 1764, Main Thread] WARNING: Wrong inner/outer window combination!: file z:/build/build/src/dom/base/Document.cpp, line 6851
[task 2019-11-29T00:20:15.761Z] 00:20:15 INFO - GECKO(2908) | [Child 1764, Main Thread] WARNING: Wrong inner/outer window combination!: file z:/build/build/src/dom/base/Document.cpp, line 6851
[task 2019-11-29T00:20:15.761Z] 00:20:15 INFO - GECKO(2908) | [Child 1764, Main Thread] WARNING: Wrong inner/outer window combination!: file z:/build/build/src/dom/base/Document.cpp, line 6851
[task 2019-11-29T00:20:15.893Z] 00:20:15 INFO - GECKO(2908) | --DOMWINDOW == 11 (000001DAD0AB2800) [pid = 1764] [serial = 426] [outer = 0000000000000000] [url = about:blank]
[task 2019-11-29T00:20:15.893Z] 00:20:15 INFO - GECKO(2908) | --DOMWINDOW == 10 (000001DACE822F20) [pid = 1764] [serial = 425] [outer = 0000000000000000] [url = about:blank]
[task 2019-11-29T00:20:15.893Z] 00:20:15 INFO - GECKO(2908) | --DOMWINDOW == 9 (000001DAD09CCC00) [pid = 1764] [serial = 427] [outer = 0000000000000000] [url = https://example.com/tests/SimpleTest/iframe-between-tests.html]
[task 2019-11-29T00:20:15.893Z] 00:20:15 INFO - GECKO(2908) | --DOMWINDOW == 8 (000001DAD09B1800) [pid = 1764] [serial = 424] [outer = 0000000000000000] [url = https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_noTrickleAnswer.html]
[task 2019-11-29T00:20:16.014Z] 00:20:16 INFO - GECKO(2908) | [Child 1764: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:335: PeerConnectionImpl: PeerConnectionImpl constructor for
[task 2019-11-29T00:20:16.014Z] 00:20:16 INFO - GECKO(2908) | [Parent 7716: Socket Thread]: D/mtransport NrIceCtx static call to find local stun addresses
[task 2019-11-29T00:20:16.014Z] 00:20:16 INFO - GECKO(2908) | [Child 1764: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:335: PeerConnectionImpl: PeerConnectionImpl constructor for
[task 2019-11-29T00:20:16.014Z] 00:20:16 INFO - GECKO(2908) | [Parent 7716: Socket Thread]: D/mtransport NrIceCtx static call to find local stun addresses
[task 2019-11-29T00:20:16.032Z] 00:20:16 INFO - GECKO(2908) | TEST DEVICES: No test device found in media.audio_loopback_dev, using fake audio streams.
[task 2019-11-29T00:20:16.032Z] 00:20:16 INFO - GECKO(2908) | TEST DEVICES: No test device found in media.video_loopback_dev, using fake video streams.
[task 2019-11-29T00:20:16.032Z] 00:20:16 INFO - GECKO(2908) | [Child 1764: Main Thread]: I/signaling [main|PeerConnectionMedia] PeerConnectionMedia.cpp:73: OnStunAddrsAvailable: receiving (4) stun addrs
[task 2019-11-29T00:20:16.032Z] 00:20:16 INFO - GECKO(2908) | [Child 1764: Main Thread]: I/signaling [main|PeerConnectionMedia] PeerConnectionMedia.cpp:73: OnStunAddrsAvailable: receiving (4) stun addrs
[task 2019-11-29T00:20:16.078Z] 00:20:16 INFO - GECKO(2908) | TEST DEVICES: No test device found in media.audio_loopback_dev, using fake audio streams.
[task 2019-11-29T00:20:16.078Z] 00:20:16 INFO - GECKO(2908) | TEST DEVICES: No test device found in media.video_loopback_dev, using fake video streams.
[task 2019-11-29T00:20:16.117Z] 00:20:16 INFO - GECKO(2908) | [Child 1764: Main Thread]: I/signaling [main|sdp_config] sdp_config.c:86: SDP: Initialized config pointer: 000001DAD073CD60
[task 2019-11-29T00:20:16.117Z] 00:20:16 INFO - GECKO(2908) | [Child 1764: Main Thread]: I/jsep [1574986816005000 (id=2147484072 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html]: stable -> have-local-offer
[task 2019-11-29T00:20:16.136Z] 00:20:16 INFO - GECKO(2908) | (generic/EMERG) Exit UDP socket connected
[task 2019-11-29T00:20:16.136Z] 00:20:16 INFO - GECKO(2908) | (ice/WARNING) z:/build/build/src/media/mtransport/third_party/nICEr/src/net/nr_socket_multi_tcp.c:617 function nr_socket_multi_tcp_listen failed with error 3
[task 2019-11-29T00:20:16.136Z] 00:20:16 INFO - GECKO(2908) | (ice/WARNING) ICE(PC:1574986816005000 (id=2147484072 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html): failed to create passive TCP host candidate: 3
[task 2019-11-29T00:20:16.136Z] 00:20:16 INFO - GECKO(2908) | (ice/WARNING) z:/build/build/src/media/mtransport/third_party/nICEr/src/net/nr_socket_multi_tcp.c:617 function nr_socket_multi_tcp_listen failed with error 3
....
[task 2019-11-29T00:21:13.727Z] 00:21:13 INFO - GECKO(2908) | (stun/INFO) STUN-CLIENT(consent): Received response; processing
[task 2019-11-29T00:21:13.727Z] 00:21:13 INFO - GECKO(2908) | (ice/INFO) ICE(PC:1574986816009000 (id=2147484072 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html)/STREAM(PC:1574986816009000 (id=2147484072 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html transport-id=transport_0 - cf326890:70e16c30eb73b447d8a2ef47364567c6)/COMP(1): Consent refreshed
[task 2019-11-29T00:21:14.458Z] 00:21:14 INFO - GECKO(2908) | (stun/INFO) STUN-CLIENT(consent): Received response; processing
[task 2019-11-29T00:21:14.458Z] 00:21:14 INFO - GECKO(2908) | (ice/INFO) ICE(PC:1574986816005000 (id=2147484072 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html)/STREAM(PC:1574986816005000 (id=2147484072 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html transport-id=transport_0 - 6e35fc30:dc893f3e4bee546fc51bde819f861e65)/COMP(1): Consent refreshed
[task 2019-11-29T00:21:16.872Z] 00:21:16 INFO - TEST-INFO | started process screenshot
[task 2019-11-29T00:21:16.934Z] 00:21:16 INFO - TEST-INFO | screenshot: exit 0
[task 2019-11-29T00:21:16.934Z] 00:21:16 INFO - <snipped 221 output lines - if you need more context, please use SimpleTest.requestCompleteLog() in your test>
[task 2019-11-29T00:21:16.935Z] 00:21:16 INFO - Buffered messages logged at 00:20:16
[task 2019-11-29T00:21:16.935Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | usernameFragment not empty
[task 2019-11-29T00:21:16.936Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | SDP MLine Index needs to exist
[task 2019-11-29T00:21:16.936Z] 00:21:16 INFO - Received: {"candidate":"candidate:0 1 UDP 2122252543 7bdf6b2f-a824-44d3-8e6a-ccba1bd231a5.local 61951 typ host","sdpMid":"0","sdpMLineIndex":0,"usernameFragment":"cf326890"} from pcRemote
[task 2019-11-29T00:21:16.937Z] 00:21:16 INFO - PeerConnectionWrapper (pcLocal): adding ICE candidate {"candidate":"candidate:0 1 UDP 2122252543 7bdf6b2f-a824-44d3-8e6a-ccba1bd231a5.local 61951 typ host","sdpMid":"0","sdpMLineIndex":0,"usernameFragment":"cf326890"}
[task 2019-11-29T00:21:16.937Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | PeerConnectionWrapper (pcLocal) successfully added an ICE candidate
[task 2019-11-29T00:21:16.938Z] 00:21:16 INFO - pcRemote: iceCandidate = {"candidate":"candidate:1 1 TCP 2105524479 7bdf6b2f-a824-44d3-8e6a-ccba1bd231a5.local 9 typ host tcptype active","sdpMid":"0","sdpMLineIndex":0,"usernameFragment":"cf326890"}
[task 2019-11-29T00:21:16.938Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | SDP mid not empty
[task 2019-11-29T00:21:16.939Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | usernameFragment not empty
[task 2019-11-29T00:21:16.939Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | SDP MLine Index needs to exist
[task 2019-11-29T00:21:16.940Z] 00:21:16 INFO - Received: {"candidate":"candidate:1 1 TCP 2105524479 7bdf6b2f-a824-44d3-8e6a-ccba1bd231a5.local 9 typ host tcptype active","sdpMid":"0","sdpMLineIndex":0,"usernameFragment":"cf326890"} from pcRemote
[task 2019-11-29T00:21:16.940Z] 00:21:16 INFO - PeerConnectionWrapper (pcLocal): adding ICE candidate {"candidate":"candidate:1 1 TCP 2105524479 7bdf6b2f-a824-44d3-8e6a-ccba1bd231a5.local 9 typ host tcptype active","sdpMid":"0","sdpMLineIndex":0,"usernameFragment":"cf326890"}
[task 2019-11-29T00:21:16.940Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | PeerConnectionWrapper (pcLocal) successfully added an ICE candidate
[task 2019-11-29T00:21:16.941Z] 00:21:16 INFO - pcRemote: iceCandidate = {"candidate":"","sdpMid":"0","sdpMLineIndex":0,"usernameFragment":"cf326890"}
[task 2019-11-29T00:21:16.941Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | SDP mid not empty
[task 2019-11-29T00:21:16.942Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | usernameFragment not empty
[task 2019-11-29T00:21:16.942Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | SDP MLine Index needs to exist
[task 2019-11-29T00:21:16.942Z] 00:21:16 INFO - Received: {"candidate":"","sdpMid":"0","sdpMLineIndex":0,"usernameFragment":"cf326890"} from pcRemote
[task 2019-11-29T00:21:16.943Z] 00:21:16 INFO - PeerConnectionWrapper (pcLocal): adding ICE candidate {"candidate":"","sdpMid":"0","sdpMLineIndex":0,"usernameFragment":"cf326890"}
[task 2019-11-29T00:21:16.943Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | PeerConnectionWrapper (pcLocal) successfully added an ICE candidate
[task 2019-11-29T00:21:16.943Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | iceGetheringState should not be undefined
[task 2019-11-29T00:21:16.944Z] 00:21:16 INFO - PeerConnectionWrapper (pcRemote): onicegatheringstatechange fired, new state is: complete
[task 2019-11-29T00:21:16.944Z] 00:21:16 INFO - pcRemote: received end of trickle ICE event
[task 2019-11-29T00:21:16.945Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | ICE gathering state has reached complete
[task 2019-11-29T00:21:16.945Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | iceConnectionState should not be undefined
[task 2019-11-29T00:21:16.946Z] 00:21:16 INFO - PeerConnectionWrapper (pcRemote): oniceconnectionstatechange fired, new state is: checking
....
[task 2019-11-29T00:21:16.946Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | PeerConnectionWrapper (pcRemote): legal ICE state transition from new to checking
[task 2019-11-29T00:21:16.947Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | iceConnectionState should not be undefined
[task 2019-11-29T00:21:16.947Z] 00:21:16 INFO - PeerConnectionWrapper (pcLocal): oniceconnectionstatechange fired, new state is: checking
[task 2019-11-29T00:21:16.948Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | PeerConnectionWrapper (pcLocal): legal ICE state transition from new to checking
[task 2019-11-29T00:21:16.948Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | iceConnectionState should not be undefined
[task 2019-11-29T00:21:16.948Z] 00:21:16 INFO - PeerConnectionWrapper (pcRemote): oniceconnectionstatechange fired, new state is: connected
[task 2019-11-29T00:21:16.949Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | PeerConnectionWrapper (pcRemote): legal ICE state transition from checking to connected
[task 2019-11-29T00:21:16.950Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | iceConnectionState should not be undefined
[task 2019-11-29T00:21:16.950Z] 00:21:16 INFO - PeerConnectionWrapper (pcLocal): oniceconnectionstatechange fired, new state is: connected
[task 2019-11-29T00:21:16.951Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | PeerConnectionWrapper (pcLocal): legal ICE state transition from checking to connected
[task 2019-11-29T00:21:16.951Z] 00:21:16 INFO - PeerConnectionWrapper (pcLocal): ICE connection state log: new,checking,connected
[task 2019-11-29T00:21:16.952Z] 00:21:16 INFO - Run step 34: PC_REMOTE_WAIT_FOR_ICE_CONNECTED
[task 2019-11-29T00:21:16.952Z] 00:21:16 INFO - PeerConnectionWrapper (pcRemote): ICE connection state log: new,checking,connected
[task 2019-11-29T00:21:16.953Z] 00:21:16 INFO - Run step 35: PC_LOCAL_VERIFY_ICE_GATHERING
[task 2019-11-29T00:21:16.953Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | PeerConnectionWrapper (pcLocal) received local trickle ICE candidates
[task 2019-11-29T00:21:16.953Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | PeerConnectionWrapper (pcLocal) ICE gathering state is not 'new'
[task 2019-11-29T00:21:16.954Z] 00:21:16 INFO - Run step 36: PC_REMOTE_VERIFY_ICE_GATHERING
[task 2019-11-29T00:21:16.954Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | PeerConnectionWrapper (pcRemote) received local trickle ICE candidates
[task 2019-11-29T00:21:16.955Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | PeerConnectionWrapper (pcRemote) ICE gathering state is not 'new'
[task 2019-11-29T00:21:16.955Z] 00:21:16 INFO - Run step 37: PC_LOCAL_WAIT_FOR_MEDIA_FLOW
[task 2019-11-29T00:21:16.956Z] 00:21:16 INFO - Checking data flow for element: local{189f0283-b954-45cf-a903-72ac1098b3d8}
[task 2019-11-29T00:21:16.956Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | Element ended should be the inverse of the MediaStream's active state
[task 2019-11-29T00:21:16.956Z] 00:21:16 INFO - TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts
[task 2019-11-29T00:21:16.957Z] 00:21:16 INFO - Found transceiver that should be receiving RTP: mid=0 currentDirection=sendrecv kind=audio track-id={416a0c6d-cec4-4e81-9466-3150de59cbff}
[task 2019-11-29T00:21:16.957Z] 00:21:16 INFO - Checking data flow for element: remote{416a0c6d-cec4-4e81-9466-3150de59cbff}
[task 2019-11-29T00:21:16.958Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | Element ended should be the inverse of the MediaStream's active state
[task 2019-11-29T00:21:16.958Z] 00:21:16 INFO - TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts
[task 2019-11-29T00:21:16.958Z] 00:21:16 INFO - Found transceiver that should be receiving RTP: mid=0 currentDirection=sendrecv kind=audio track-id={416a0c6d-cec4-4e81-9466-3150de59cbff}
[task 2019-11-29T00:21:16.958Z] 00:21:16 INFO - waitForRtpFlow({416a0c6d-cec4-4e81-9466-3150de59cbff})
[task 2019-11-29T00:21:16.958Z] 00:21:16 INFO - waitForRtpFlow({189f0283-b954-45cf-a903-72ac1098b3d8})
[task 2019-11-29T00:21:16.960Z] 00:21:16 INFO - Element local{189f0283-b954-45cf-a903-72ac1098b3d8} has enough data.
[task 2019-11-29T00:21:16.960Z] 00:21:16 INFO - Element remote{416a0c6d-cec4-4e81-9466-3150de59cbff} has enough data.
[task 2019-11-29T00:21:16.961Z] 00:21:16 INFO - Checking for stats in [["Yo7t",{"id":"Yo7t","timestamp":1574986816272,"type":"candidate-pair","bytesReceived":781,"bytesSent":799,"lastPacketReceivedTimestamp":334558528327,"lastPacketSentTimestamp":334558528329,"localCandidateId":"hYzc","nominated":true,"priority":9115005270282338000,"readable":true,"remoteCandidateId":"px/m","selected":true,"state":"succeeded","transportId":"transport_0","writable":true}],["hYzc",{"id":"hYzc","timestamp":1574986816272,"type":"local-candidate","address":"c7400ca5-8dd7-4369-b448-9edfc653a0fa.local","candidateType":"host","port":61948,"priority":2122252543,"protocol":"udp"}],["inqr",{"id":"inqr","timestamp":1574986816272,"type":"local-candidate","address":"c7400ca5-8dd7-4369-b448-9edfc653a0fa.local","candidateType":"host","port":56839,"priority":2105524479,"protocol":"tcp"}],["px/m",{"id":"px/m","timestamp":1574986816272,"type":"remote-candidate","address":"7bdf6b2f-a824-44d3-8e6a-ccba1bd231a5.local","candidateType":"host","port":61951,"priority":2122252543,"protocol":"udp"}],["VqYX",{"id":"VqYX","timestamp":1574986816272,"type":"remote-candidate","address":"7bdf6b2f-a824-44d3-8e6a-ccba1bd231a5.local","candidateType":"host","port":9,"priority":2105524479,"protocol":"tcp"}],["inbound_rtp_audio_0",{"id":"inbound_rtp_audio_0","timestamp":1574986816272,"type":"inbound-rtp","kind":"audio","mediaType":"audio","ssrc":1255091259,"jitter":0,"packetsLost":0,"packetsReceived":0,"bytesReceived":0,"nackCount":0}]] for audio track {416a0c6d-cec4-4e81-9466-3150de59cbff}retry number 0
[task 2019-11-29T00:21:16.961Z] 00:21:16 INFO - Should have RTP stats for track {416a0c6d-cec4-4e81-9466-3150de59cbff}
[task 2019-11-29T00:21:16.961Z] 00:21:16 INFO - RTP stats: {"id":"inbound_rtp_audio_0","timestamp":1574986816272,"type":"inbound-rtp","kind":"audio","mediaType":"audio","ssrc":1255091259,"jitter":0,"packetsLost":0,"packetsReceived":0,"bytesReceived":0,"nackCount":0}
[task 2019-11-29T00:21:16.961Z] 00:21:16 INFO - Track {416a0c6d-cec4-4e81-9466-3150de59cbff} has 0 inbound-rtp RTP packets.
[task 2019-11-29T00:21:16.962Z] 00:21:16 INFO - TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts
[task 2019-11-29T00:21:16.962Z] 00:21:16 INFO - Checking for stats in [["Yo7t",{"id":"Yo7t","timestamp":1574986816274,"type":"candidate-pair","bytesReceived":781,"bytesSent":799,"lastPacketReceivedTimestamp":334558528327,"lastPacketSentTimestamp":334558528329,"localCandidateId":"hYzc","nominated":true,"priority":9115005270282338000,"readable":true,"remoteCandidateId":"px/m","selected":true,"state":"succeeded","transportId":"transport_0","writable":true}],["hYzc",{"id":"hYzc","timestamp":1574986816274,"type":"local-candidate","address":"c7400ca5-8dd7-4369-b448-9edfc653a0fa.local","candidateType":"host","port":61948,"priority":2122252543,"protocol":"udp"}],["inqr",{"id":"inqr","timestamp":1574986816274,"type":"local-candidate","address":"c7400ca5-8dd7-4369-b448-9edfc653a0fa.local","candidateType":"host","port":56839,"priority":2105524479,"protocol":"tcp"}],["px/m",{"id":"px/m","timestamp":1574986816274,"type":"remote-candidate","address":"7bdf6b2f-a824-44d3-8e6a-ccba1bd231a5.local","candidateType":"host","port":61951,"priority":2122252543,"protocol":"udp"}],["VqYX",{"id":"VqYX","timestamp":1574986816274,"type":"remote-candidate","address":"7bdf6b2f-a824-44d3-8e6a-ccba1bd231a5.local","candidateType":"host","port":9,"priority":2105524479,"protocol":"tcp"}],["outbound_rtp_audio_0",{"id":"outbound_rtp_audio_0","timestamp":1574986816274,"type":"outbound-rtp","kind":"audio","mediaType":"audio","ssrc":251300225,"bytesSent":0,"packetsSent":0,"nackCount":0,"remoteId":""}]] for audio track {189f0283-b954-45cf-a903-72ac1098b3d8}retry number 0
[task 2019-11-29T00:21:16.962Z] 00:21:16 INFO - Should have RTP stats for track {189f0283-b954-45cf-a903-72ac1098b3d8}
[task 2019-11-29T00:21:16.963Z] 00:21:16 INFO - RTP stats: {"id":"outbound_rtp_audio_0","timestamp":1574986816274,"type":"outbound-rtp","kind":"audio","mediaType":"audio","ssrc":251300225,"bytesSent":0,"packetsSent":0,"nackCount":0,"remoteId":""}
[task 2019-11-29T00:21:16.963Z] 00:21:16 INFO - Track {189f0283-b954-45cf-a903-72ac1098b3d8} has 0 outbound-rtp RTP packets.
[task 2019-11-29T00:21:16.963Z] 00:21:16 INFO - TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts
[task 2019-11-29T00:21:16.964Z] 00:21:16 INFO - Checking for stats in [["Yo7t",{"id":"Yo7t","timestamp":1574986816781,"type":"candidate-pair","bytesReceived":8881,"bytesSent":8899,"lastPacketReceivedTimestamp":334558528724,"lastPacketSentTimestamp":334558528724,"localCandidateId":"hYzc","nominated":true,"priority":9115005270282338000,"readable":true,"remoteCandidateId":"px/m","selected":true,"state":"succeeded","transportId":"transport_0","writable":true}],["hYzc",{"id":"hYzc","timestamp":1574986816781,"type":"local-candidate","address":"c7400ca5-8dd7-4369-b448-9edfc653a0fa.local","candidateType":"host","port":61948,"priority":2122252543,"protocol":"udp"}],["inqr",{"id":"inqr","timestamp":1574986816781,"type":"local-candidate","address":"c7400ca5-8dd7-4369-b448-9edfc653a0fa.local","candidateType":"host","port":56839,"priority":2105524479,"protocol":"tcp"}],["px/m",{"id":"px/m","timestamp":1574986816781,"type":"remote-candidate","address":"7bdf6b2f-a824-44d3-8e6a-ccba1bd231a5.local","candidateType":"host","port":61951,"priority":2122252543,"protocol":"udp"}],["VqYX",{"id":"VqYX","timestamp":1574986816781,"type":"remote-candidate","address":"7bdf6b2f-a824-44d3-8e6a-ccba1bd231a5.local","candidateType":"host","port":9,"priority":2105524479,"protocol":"tcp"}],["inbound_rtp_audio_0",{"id":"inbound_rtp_audio_0","timestamp":1574986816781,"type":"inbound-rtp","kind":"audio","mediaType":"audio","ssrc":1255091259,"jitter":0,"packetsLost":0,"packetsReceived":40,"bytesReceived":7400,"nackCount":0}]] for audio track {416a0c6d-cec4-4e81-9466-3150de59cbff}retry number 1
[task 2019-11-29T00:21:16.965Z] 00:21:16 INFO - Should have RTP stats for track {416a0c6d-cec4-4e81-9466-3150de59cbff}
[task 2019-11-29T00:21:16.965Z] 00:21:16 INFO - RTP stats: {"id":"inbound_rtp_audio_0","timestamp":1574986816781,"type":"inbound-rtp","kind":"audio","mediaType":"audio","ssrc":1255091259,"jitter":0,"packetsLost":0,"packetsReceived":40,"bytesReceived":7400,"nackCount":0}
[task 2019-11-29T00:21:16.965Z] 00:21:16 INFO - Track {416a0c6d-cec4-4e81-9466-3150de59cbff} has 40 inbound-rtp RTP packets.
[task 2019-11-29T00:21:16.965Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | RTP flowing for audio track {416a0c6d-cec4-4e81-9466-3150de59cbff}
[task 2019-11-29T00:21:16.966Z] 00:21:16 INFO - Checking for stats in [["Yo7t",{"id":"Yo7t","timestamp":1574986816782,"type":"candidate-pair","bytesReceived":8881,"bytesSent":8899,"lastPacketReceivedTimestamp":334558528724,"lastPacketSentTimestamp":334558528724,"localCandidateId":"hYzc","nominated":true,"priority":9115005270282338000,"readable":true,"remoteCandidateId":"px/m","selected":true,"state":"succeeded","transportId":"transport_0","writable":true}],["hYzc",{"id":"hYzc","timestamp":1574986816782,"type":"local-candidate","address":"c7400ca5-8dd7-4369-b448-9edfc653a0fa.local","candidateType":"host","port":61948,"priority":2122252543,"protocol":"udp"}],["inqr",{"id":"inqr","timestamp":1574986816782,"type":"local-candidate","address":"c7400ca5-8dd7-4369-b448-9edfc653a0fa.local","candidateType":"host","port":56839,"priority":2105524479,"protocol":"tcp"}],["px/m",{"id":"px/m","timestamp":1574986816782,"type":"remote-candidate","address":"7bdf6b2f-a824-44d3-8e6a-ccba1bd231a5.local","candidateType":"host","port":61951,"priority":2122252543,"protocol":"udp"}],["VqYX",{"id":"VqYX","timestamp":1574986816782,"type":"remote-candidate","address":"7bdf6b2f-a824-44d3-8e6a-ccba1bd231a5.local","candidateType":"host","port":9,"priority":2105524479,"protocol":"tcp"}],["outbound_rtp_audio_0",{"id":"outbound_rtp_audio_0","timestamp":1574986816783,"type":"outbound-rtp","kind":"audio","mediaType":"audio","ssrc":251300225,"bytesSent":7400,"packetsSent":40,"nackCount":0,"remoteId":""}]] for audio track {189f0283-b954-45cf-a903-72ac1098b3d8}retry number 1
[task 2019-11-29T00:21:16.966Z] 00:21:16 INFO - Should have RTP stats for track {189f0283-b954-45cf-a903-72ac1098b3d8}
[task 2019-11-29T00:21:16.967Z] 00:21:16 INFO - RTP stats: {"id":"outbound_rtp_audio_0","timestamp":1574986816783,"type":"outbound-rtp","kind":"audio","mediaType":"audio","ssrc":251300225,"bytesSent":7400,"packetsSent":40,"nackCount":0,"remoteId":""}
[task 2019-11-29T00:21:16.967Z] 00:21:16 INFO - Track {189f0283-b954-45cf-a903-72ac1098b3d8} has 40 outbound-rtp RTP packets.
[task 2019-11-29T00:21:16.967Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | RTP flowing for audio track {189f0283-b954-45cf-a903-72ac1098b3d8}
[task 2019-11-29T00:21:16.968Z] 00:21:16 INFO - Run step 38: PC_REMOTE_WAIT_FOR_MEDIA_FLOW
[task 2019-11-29T00:21:16.968Z] 00:21:16 INFO - Checking data flow for element: local{28e917c7-7827-48be-a57e-8fee1a5032b6}
[task 2019-11-29T00:21:16.969Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | Element ended should be the inverse of the MediaStream's active state
[task 2019-11-29T00:21:16.969Z] 00:21:16 INFO - TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts
[task 2019-11-29T00:21:16.969Z] 00:21:16 INFO - Found transceiver that should be receiving RTP: mid=0 currentDirection=sendrecv kind=audio track-id={6b2e7154-0826-45bb-8665-ca9aacbbb0d3}
[task 2019-11-29T00:21:16.970Z] 00:21:16 INFO - Checking data flow for element: remote{6b2e7154-0826-45bb-8665-ca9aacbbb0d3}
[task 2019-11-29T00:21:16.970Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | Element ended should be the inverse of the MediaStream's active state
[task 2019-11-29T00:21:16.971Z] 00:21:16 INFO - TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts
[task 2019-11-29T00:21:16.971Z] 00:21:16 INFO - Found transceiver that should be receiving RTP: mid=0 currentDirection=sendrecv kind=audio track-id={6b2e7154-0826-45bb-8665-ca9aacbbb0d3}
[task 2019-11-29T00:21:16.971Z] 00:21:16 INFO - waitForRtpFlow({6b2e7154-0826-45bb-8665-ca9aacbbb0d3})
[task 2019-11-29T00:21:16.972Z] 00:21:16 INFO - waitForRtpFlow({28e917c7-7827-48be-a57e-8fee1a5032b6})
[task 2019-11-29T00:21:16.972Z] 00:21:16 INFO - Element local{28e917c7-7827-48be-a57e-8fee1a5032b6} has enough data.
[task 2019-11-29T00:21:16.973Z] 00:21:16 INFO - Element remote{6b2e7154-0826-45bb-8665-ca9aacbbb0d3} has enough data.
[task 2019-11-29T00:21:16.973Z] 00:21:16 INFO - Checking for stats in [["mjle",{"id":"mjle","timestamp":1574986816788,"type":"candidate-pair","bytesReceived":8899,"bytesSent":8881,"lastPacketReceivedTimestamp":334558528725,"lastPacketSentTimestamp":334558528724,"localCandidateId":"rQf4","nominated":true,"priority":9115005270282338000,"readable":true,"remoteCandidateId":"J3aA","selected":true,"state":"succeeded","transportId":"transport_0","writable":true}],["rQf4",{"id":"rQf4","timestamp":1574986816788,"type":"local-candidate","address":"7bdf6b2f-a824-44d3-8e6a-ccba1bd231a5.local","candidateType":"host","port":61951,"priority":2122252543,"protocol":"udp"}],["6iYz",{"id":"6iYz","timestamp":1574986816788,"type":"local-candidate","address":"7bdf6b2f-a824-44d3-8e6a-ccba1bd231a5.local","candidateType":"host","port":52786,"priority":2105524479,"protocol":"tcp"}],["J3aA",{"id":"J3aA","timestamp":1574986816788,"type":"remote-candidate","address":"c7400ca5-8dd7-4369-b448-9edfc653a0fa.local","candidateType":"host","port":61948,"priority":2122252543,"protocol":"udp"}],["VqYX",{"id":"VqYX","timestamp":1574986816788,"type":"remote-candidate","address":"c7400ca5-8dd7-4369-b448-9edfc653a0fa.local","candidateType":"host","port":9,"priority":2105524479,"protocol":"tcp"}],["inbound_rtp_audio_0",{"id":"inbound_rtp_audio_0","timestamp":1574986816789,"type":"inbound-rtp","kind":"audio","mediaType":"audio","ssrc":251300225,"jitter":0,"packetsLost":0,"packetsReceived":40,"bytesReceived":7400,"nackCount":0}]] for audio track {6b2e7154-0826-45bb-8665-ca9aacbbb0d3}retry number 0
[task 2019-11-29T00:21:16.974Z] 00:21:16 INFO - Should have RTP stats for track {6b2e7154-0826-45bb-8665-ca9aacbbb0d3}
[task 2019-11-29T00:21:16.974Z] 00:21:16 INFO - RTP stats: {"id":"inbound_rtp_audio_0","timestamp":1574986816789,"type":"inbound-rtp","kind":"audio","mediaType":"audio","ssrc":251300225,"jitter":0,"packetsLost":0,"packetsReceived":40,"bytesReceived":7400,"nackCount":0}
[task 2019-11-29T00:21:16.974Z] 00:21:16 INFO - Track {6b2e7154-0826-45bb-8665-ca9aacbbb0d3} has 40 inbound-rtp RTP packets.
[task 2019-11-29T00:21:16.975Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | RTP flowing for audio track {6b2e7154-0826-45bb-8665-ca9aacbbb0d3}
[task 2019-11-29T00:21:16.975Z] 00:21:16 INFO - Checking for stats in [["mjle",{"id":"mjle","timestamp":1574986816789,"type":"candidate-pair","bytesReceived":8899,"bytesSent":8881,"lastPacketReceivedTimestamp":334558528725,"lastPacketSentTimestamp":334558528724,"localCandidateId":"rQf4","nominated":true,"priority":9115005270282338000,"readable":true,"remoteCandidateId":"J3aA","selected":true,"state":"succeeded","transportId":"transport_0","writable":true}],["rQf4",{"id":"rQf4","timestamp":1574986816789,"type":"local-candidate","address":"7bdf6b2f-a824-44d3-8e6a-ccba1bd231a5.local","candidateType":"host","port":61951,"priority":2122252543,"protocol":"udp"}],["6iYz",{"id":"6iYz","timestamp":1574986816789,"type":"local-candidate","address":"7bdf6b2f-a824-44d3-8e6a-ccba1bd231a5.local","candidateType":"host","port":52786,"priority":2105524479,"protocol":"tcp"}],["J3aA",{"id":"J3aA","timestamp":1574986816789,"type":"remote-candidate","address":"c7400ca5-8dd7-4369-b448-9edfc653a0fa.local","candidateType":"host","port":61948,"priority":2122252543,"protocol":"udp"}],["VqYX",{"id":"VqYX","timestamp":1574986816789,"type":"remote-candidate","address":"c7400ca5-8dd7-4369-b448-9edfc653a0fa.local","candidateType":"host","port":9,"priority":2105524479,"protocol":"tcp"}],["outbound_rtp_audio_0",{"id":"outbound_rtp_audio_0","timestamp":1574986816789,"type":"outbound-rtp","kind":"audio","mediaType":"audio","ssrc":1255091259,"bytesSent":7400,"packetsSent":40,"nackCount":0,"remoteId":""}]] for audio track {28e917c7-7827-48be-a57e-8fee1a5032b6}retry number 0
[task 2019-11-29T00:21:16.975Z] 00:21:16 INFO - Should have RTP stats for track {28e917c7-7827-48be-a57e-8fee1a5032b6}
[task 2019-11-29T00:21:16.976Z] 00:21:16 INFO - RTP stats: {"id":"outbound_rtp_audio_0","timestamp":1574986816789,"type":"outbound-rtp","kind":"audio","mediaType":"audio","ssrc":1255091259,"bytesSent":7400,"packetsSent":40,"nackCount":0,"remoteId":""}
[task 2019-11-29T00:21:16.976Z] 00:21:16 INFO - Track {28e917c7-7827-48be-a57e-8fee1a5032b6} has 40 outbound-rtp RTP packets.
[task 2019-11-29T00:21:16.977Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | RTP flowing for audio track {28e917c7-7827-48be-a57e-8fee1a5032b6}
[task 2019-11-29T00:21:16.977Z] 00:21:16 INFO - Buffered messages finished
[task 2019-11-29T00:21:16.978Z] 00:21:16 INFO - TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | Error in test execution: Error: Element local{28e917c7-7827-48be-a57e-8fee1a5032b6} should progress currentTime timeout/<@https://example.com/tests/dom/media/tests/mochitest/head.js:652:42 ... promise callbacktimeout@https://example.com/tests/dom/media/tests/mochitest/head.js:652: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_REMOTE_WAIT_FOR_MEDIA_FLOW@https://example.com/tests/dom/media/tests/mochitest/templates.js:517:26 ... execute/</<@https://example.com/tests/dom/media/tests/mochitest/head.js:944:32 ... promise callbackexecute/<@https://example.com/tests/dom/media/tests/mochitest/head.js:942:21 ... execute@https://example.com/tests/dom/media/tests/mochitest/head.js:937:8 ... PeerConnectionTest.prototype.run@https://example.com/tests/dom/media/tests/mochitest/pc.js:574:6 ... @https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html:20:10 ... runNetworkTest/<@https://example.com/tests/dom/media/tests/mochitest/pc.js:2556:11 ... asyncrunTestWhenReady/<@https://example.com/tests/dom/media/tests/mochitest/head.js:492:30 ... promise callbackrunTestWhenReady@https://example.com/tests/dom/media/tests/mochitest/head.js:492:6 ... runNetworkTest@https://example.com/tests/dom/media/tests/mochitest/pc.js:2537:9 ... async*@https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html:16:17 ...
[task 2019-11-29T00:21:16.978Z] 00:21:16 INFO - SimpleTest.ok@https://example.com/tests/SimpleTest/SimpleTest.js:277:18
[task 2019-11-29T00:21:16.978Z] 00:21:16 INFO - execute/<@https://example.com/tests/dom/media/tests/mochitest/head.js:948:11
[task 2019-11-29T00:21:16.978Z] 00:21:16 INFO - promise callbackexecute@https://example.com/tests/dom/media/tests/mochitest/head.js:947:8
[task 2019-11-29T00:21:16.978Z] 00:21:16 INFO - PeerConnectionTest.prototype.run@https://example.com/tests/dom/media/tests/mochitest/pc.js:574:6
[task 2019-11-29T00:21:16.978Z] 00:21:16 INFO - @https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html:20:10
[task 2019-11-29T00:21:16.979Z] 00:21:16 INFO - runNetworkTest/<@https://example.com/tests/dom/media/tests/mochitest/pc.js:2556:11
[task 2019-11-29T00:21:16.979Z] 00:21:16 INFO - async
runTestWhenReady/<@https://example.com/tests/dom/media/tests/mochitest/head.js:492:30
[task 2019-11-29T00:21:16.979Z] 00:21:16 INFO - promise callbackrunTestWhenReady@https://example.com/tests/dom/media/tests/mochitest/head.js:492:6
[task 2019-11-29T00:21:16.979Z] 00:21:16 INFO - runNetworkTest@https://example.com/tests/dom/media/tests/mochitest/pc.js:2537:9
[task 2019-11-29T00:21:16.979Z] 00:21:16 INFO - async
@https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html:16:17
[task 2019-11-29T00:21:16.979Z] 00:21:16 INFO - TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts
[task 2019-11-29T00:21:16.979Z] 00:21:16 INFO - Closing peer connections
[task 2019-11-29T00:21:16.979Z] 00:21:16 INFO - Waiting for track {416a0c6d-cec4-4e81-9466-3150de59cbff} (audio) to end.
[task 2019-11-29T00:21:16.981Z] 00:21:16 INFO - TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts
[task 2019-11-29T00:21:16.981Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | iceConnectionState should not be undefined
[task 2019-11-29T00:21:16.981Z] 00:21:16 INFO - PeerConnectionWrapper (pcLocal): oniceconnectionstatechange fired, new state is: closed
[task 2019-11-29T00:21:16.982Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | PeerConnectionWrapper (pcLocal): legal ICE state transition from connected to closed
[task 2019-11-29T00:21:16.982Z] 00:21:16 INFO - GECKO(2908) | [Child 1764: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2190: CloseInt: Closing PeerConnectionImpl 4d2b7881f40606c3; ending call
[task 2019-11-29T00:21:16.982Z] 00:21:16 INFO - GECKO(2908) | [Child 1764: Main Thread]: I/jsep [1574986816005000 (id=2147484072 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html]: stable -> closed
[task 2019-11-29T00:21:16.982Z] 00:21:16 INFO - PeerConnectionWrapper (pcLocal): "onsignalingstatechange" event fired
[task 2019-11-29T00:21:16.982Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | signalingState is closed
[task 2019-11-29T00:21:16.982Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | PeerConnectionWrapper (pcLocal): legal signaling state transition from stable to closed
[task 2019-11-29T00:21:16.982Z] 00:21:16 INFO - PeerConnectionWrapper (pcLocal): Closed connection.
[task 2019-11-29T00:21:16.983Z] 00:21:16 INFO - Waiting for track {6b2e7154-0826-45bb-8665-ca9aacbbb0d3} (audio) to end.
[task 2019-11-29T00:21:16.983Z] 00:21:16 INFO - TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts
[task 2019-11-29T00:21:16.983Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | iceConnectionState should not be undefined
[task 2019-11-29T00:21:16.983Z] 00:21:16 INFO - PeerConnectionWrapper (pcRemote): oniceconnectionstatechange fired, new state is: closed
[task 2019-11-29T00:21:16.983Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | PeerConnectionWrapper (pcRemote): legal ICE state transition from connected to closed
[task 2019-11-29T00:21:16.983Z] 00:21:16 INFO - GECKO(2908) | [Child 1764: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2190: CloseInt: Closing PeerConnectionImpl a76694a87b4c3e8b; ending call
[task 2019-11-29T00:21:16.983Z] 00:21:16 INFO - GECKO(2908) | [Child 1764: Main Thread]: I/jsep [1574986816009000 (id=2147484072 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html]: stable -> closed
[task 2019-11-29T00:21:16.983Z] 00:21:16 INFO - PeerConnectionWrapper (pcRemote): "onsignalingstatechange" event fired
[task 2019-11-29T00:21:16.983Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | signalingState is closed
[task 2019-11-29T00:21:16.983Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | PeerConnectionWrapper (pcRemote): legal signaling state transition from stable to closed
[task 2019-11-29T00:21:16.984Z] 00:21:16 INFO - PeerConnectionWrapper (pcRemote): Closed connection.
[task 2019-11-29T00:21:16.984Z] 00:21:16 INFO - TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts
[task 2019-11-29T00:21:16.984Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | Event target should be the correct track
[task 2019-11-29T00:21:16.984Z] 00:21:16 INFO - PeerConnectionWrapper (pcLocal) ended fired for track {416a0c6d-cec4-4e81-9466-3150de59cbff}
[task 2019-11-29T00:21:16.984Z] 00:21:16 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | Event target should be the correct track
[task 2019-11-29T00:21:16.984Z] 00:21:16 INFO - PeerConnectionWrapper (pcRemote) ended fired for track {6b2e7154-0826-45bb-8665-ca9aacbbb0d3}
[task 2019-11-29T00:21:16.984Z] 00:21:16 INFO - GECKO(2908) | MEMORY STAT | vsize 2103982MB | vsizeMaxContiguous 68723479MB | residentFast 149MB | heapAllocated 28MB
[task 2019-11-29T00:21:16.984Z] 00:21:16 INFO - TEST-OK | dom/media/tests/mochitest/test_peerConnection_noTrickleOffer.html | took 61551ms

Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → INCOMPLETE
Status: REOPENED → RESOLVED
Closed: 5 years ago5 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.