Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=234722154&repo=mozilla-inbound&lineNumber=53557
[task 2019-03-19T10:07:49.414Z] 10:07:49 INFO - TEST-OK | /webrtc/promises-call.html | took 1422ms
[task 2019-03-19T10:07:49.416Z] 10:07:49 INFO - PID 8392 | 1552990069411 Marionette INFO Stopped listening on port 2828
[task 2019-03-19T10:07:49.440Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/mtransport Created SRTP flow!
[task 2019-03-19T10:07:49.440Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel dtls open
[task 2019-03-19T10:07:49.440Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Calling usrsctp_bind
[task 2019-03-19T10:07:49.441Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Calling usrsctp_connect
[task 2019-03-19T10:07:49.441Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel usrsctp: PMTUD disabled, MTU set to 1200
[task 2019-03-19T10:07:49.442Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: I/mtransport Flow[transport_0(none)]; Layer[dtls]: ****** SSL handshake completed ******
[task 2019-03-19T10:07:49.443Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: I/mtransport Flow[transport_0(none)]; Layer[dtls]: Selected ALPN string: webrtc
[task 2019-03-19T10:07:49.444Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/mtransport Created SRTP flow!
[task 2019-03-19T10:07:49.444Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel dtls open
[task 2019-03-19T10:07:49.447Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Calling usrsctp_bind
[task 2019-03-19T10:07:49.449Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Calling usrsctp_connect
[task 2019-03-19T10:07:49.450Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel usrsctp: PMTUD disabled, MTU set to 1200
[task 2019-03-19T10:07:49.451Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel SendDeferredMessages called, pending type: 0
[task 2019-03-19T10:07:49.451Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel SendDeferredMessages called, pending type: 0
[task 2019-03-19T10:07:49.455Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Association change: SCTP_COMM_UP
[task 2019-03-19T10:07:49.456Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Negotiated number of incoming streams: 256
[task 2019-03-19T10:07:49.456Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel DTLS connect() succeeded! Entering connected mode
[task 2019-03-19T10:07:49.457Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Association change: streams (in/out) = (256/256)
[task 2019-03-19T10:07:49.457Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Supports: PR
[task 2019-03-19T10:07:49.458Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Supports: AUTH
[task 2019-03-19T10:07:49.458Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Supports: ASCONF
[task 2019-03-19T10:07:49.459Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Supports: MULTIBUF
[task 2019-03-19T10:07:49.461Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Supports: RE-CONFIG
[task 2019-03-19T10:07:49.461Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Association change: SCTP_COMM_UP
[task 2019-03-19T10:07:49.462Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Negotiated number of incoming streams: 256
[task 2019-03-19T10:07:49.463Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel DTLS connect() succeeded! Entering connected mode
[task 2019-03-19T10:07:49.463Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Processing queued open for 0x60f0000a0630 (65535)
[task 2019-03-19T10:07:49.465Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Sent buffer (written=19, len=19, left=0)
[task 2019-03-19T10:07:49.466Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel OpenFinish: sending ON_CHANNEL_OPEN for 0x60f0000a0630
[task 2019-03-19T10:07:49.466Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Association change: streams (in/out) = (256/256)
[task 2019-03-19T10:07:49.467Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Supports: PR
[task 2019-03-19T10:07:49.469Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Supports: AUTH
[task 2019-03-19T10:07:49.469Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Supports: ASCONF
[task 2019-03-19T10:07:49.469Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Supports: MULTIBUF
[task 2019-03-19T10:07:49.469Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Supports: RE-CONFIG
[task 2019-03-19T10:07:49.471Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: D/DataChannel 0x60f0000a0720(0x60f0000a0630): OnChannelConnected - Dispatching
[task 2019-03-19T10:07:49.472Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Handling DCEP message of length 19
[task 2019-03-19T10:07:49.472Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel HandleOpenRequestMessage: length 19, sizeof(req) = 13
[task 2019-03-19T10:07:49.475Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel HandleOpenRequestMessage: sending ON_CHANNEL_CREATED for channel/: 1 (state 4)
[task 2019-03-19T10:07:49.475Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel HandleOpenRequestMessage: deferring sending ON_CHANNEL_OPEN for 0x60f0001ee6e0
[task 2019-03-19T10:07:49.476Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Sent buffer (written=1, len=1, left=0)
[task 2019-03-19T10:07:49.476Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: D/DataChannel Init: origin = http://web-platform.test:8000
[task 2019-03-19T10:07:49.477Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: D/DataChannel 0x60f0000cd270(0x60f0001ee6e0): OnChannelConnected - Dispatching
[task 2019-03-19T10:07:49.479Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Handling DCEP message of length 1
[task 2019-03-19T10:07:49.479Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel OpenAck received for stream 1, waiting=0
[task 2019-03-19T10:07:49.480Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel SendDeferredMessages called, pending type: 0
[task 2019-03-19T10:07:49.482Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel SendDeferredMessages called, pending type: 0
[task 2019-03-19T10:07:49.674Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: E/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2717: GetStats: Found no pipelines matching selector.
[task 2019-03-19T10:07:49.681Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2313: CloseInt: Closing PeerConnectionImpl 6f04a6a42f94e55b; ending call
[task 2019-03-19T10:07:49.681Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: I/jsep [1552990069027057 (id=141733920771 url=http://web-platform.test:8000/webrtc/promises-call.html)]: stable -> closed
[task 2019-03-19T10:07:49.682Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2319: CloseInt: Destroying DataChannelConnection 0x61600001e680 for 6f04a6a42f94e55b
[task 2019-03-19T10:07:49.682Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: D/DataChannel Destroying DataChannelConnection 0x61600001e680
[task 2019-03-19T10:07:49.689Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: D/DataChannel Closing all channels (connection 0x61600001e680)
[task 2019-03-19T10:07:49.690Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: D/DataChannel Connection 0x61600001e680/Channel 0x60f0000a0630: Closing stream 1
[task 2019-03-19T10:07:49.690Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: D/DataChannel Connection 0x61600001e680: Resetting outgoing stream 1
[task 2019-03-19T10:07:49.690Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: D/DataChannel Destroying Data channel 1
[task 2019-03-19T10:07:49.691Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: D/DataChannel Connection 0x61600001e680: Sending outgoing stream reset for 1 streams
[task 2019-03-19T10:07:49.691Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Deregistered 0x61600001e680 from the SCTP stack.
[task 2019-03-19T10:07:49.692Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Incoming: Channel 1 closed, state 1
[task 2019-03-19T10:07:49.693Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Connection 0x61600008c180: Resetting outgoing stream 1
[task 2019-03-19T10:07:49.693Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Disconnected DataChannel 0x60f0001ee6e0 from connection 0x61600008c180
[task 2019-03-19T10:07:49.694Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Destroying Data channel 1
[task 2019-03-19T10:07:49.695Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Sending 1 pending resets
[task 2019-03-19T10:07:49.695Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Connection 0x61600008c180: Sending outgoing stream reset for 1 streams
[task 2019-03-19T10:07:49.696Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: E/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2717: GetStats: Found no pipelines matching selector.
[task 2019-03-19T10:07:49.696Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2313: CloseInt: Closing PeerConnectionImpl 9ae82075615f08e5; ending call
[task 2019-03-19T10:07:49.698Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: I/jsep [1552990069073122 (id=141733920771 url=http://web-platform.test:8000/webrtc/promises-call.html)]: stable -> closed
[task 2019-03-19T10:07:49.699Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2319: CloseInt: Destroying DataChannelConnection 0x61600008c180 for 9ae82075615f08e5
[task 2019-03-19T10:07:49.700Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: D/DataChannel Destroying DataChannelConnection 0x61600008c180
[task 2019-03-19T10:07:49.700Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: D/DataChannel Closing all channels (connection 0x61600008c180)
[task 2019-03-19T10:07:49.701Z] 10:07:49 INFO - PID 8392 | [Child 13621: Socket Thread]: D/DataChannel Deregistered 0x61600008c180 from the SCTP stack.
[task 2019-03-19T10:07:49.702Z] 10:07:49 INFO - PID 8392 | (generic/ERR) UDP socket error:Internal error at /builds/worker/workspace/build/src/dom/network/UDPSocketParent.cpp:392 this=0x616000091880
[task 2019-03-19T10:07:49.703Z] 10:07:49 INFO - PID 8392 | (generic/ERR) UDP socket error:Internal error at /builds/worker/workspace/build/src/dom/network/UDPSocketParent.cpp:392 this=0x616000091880
[task 2019-03-19T10:07:49.703Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: D/DataChannel 0x60f0000a0720(0x60f0000a0630): OnChannelClosed - Dispatching
[task 2019-03-19T10:07:49.706Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: D/DataChannel 0x60f0000cd270(0x60f0001ee6e0): OnChannelClosed - Dispatching
[task 2019-03-19T10:07:49.722Z] 10:07:49 INFO - PID 8392 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-03-19T10:07:49.780Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: D/DataChannel Shutting down SCTP
[task 2019-03-19T10:07:49.819Z] 10:07:49 INFO - PID 8392 | ###!!! [Child][MessageChannel] Error: (msgtype=0x3600FD,name=PContent::Msg_AccumulateChildHistograms) Closed channel: cannot send/recv
[task 2019-03-19T10:07:49.820Z] 10:07:49 INFO - PID 8392 | ###!!! [Child][MessageChannel] Error: (msgtype=0x3600FE,name=PContent::Msg_AccumulateChildKeyedHistograms) Closed channel: cannot send/recv
[task 2019-03-19T10:07:49.821Z] 10:07:49 INFO - PID 8392 | ###!!! [Child][MessageChannel] Error: (msgtype=0x360102,name=PContent::Msg_RecordDiscardedData) Closed channel: cannot send/recv
[task 2019-03-19T10:07:49.842Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: D/DataChannel Deleting DataChannelConnection 0x61600001e680
[task 2019-03-19T10:07:49.843Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: D/DataChannel Deleting DataChannelConnection 0x61600008c180
[task 2019-03-19T10:07:49.882Z] 10:07:49 INFO - PID 8392 | Timecard created 1552990069.021508
[task 2019-03-19T10:07:49.884Z] 10:07:49 INFO - PID 8392 | Timestamp | Delta | Event | File | Function
[task 2019-03-19T10:07:49.885Z] 10:07:49 INFO - PID 8392 | ======================================================================================================================
[task 2019-03-19T10:07:49.886Z] 10:07:49 INFO - PID 8392 | 0.000201 | 0.000201 | Constructor Completed | PeerConnectionImpl.cpp:338 | PeerConnectionImpl
[task 2019-03-19T10:07:49.887Z] 10:07:49 INFO - PID 8392 | 0.005640 | 0.005439 | Initializing PC Ctx | PeerConnectionImpl.cpp:465 | Initialize
[task 2019-03-19T10:07:49.887Z] 10:07:49 INFO - PID 8392 | 0.091162 | 0.085522 | Create Offer | PeerConnectionImpl.cpp:1256 | CreateOffer
[task 2019-03-19T10:07:49.888Z] 10:07:49 INFO - PID 8392 | 0.095778 | 0.004616 | Set Local Description | PeerConnectionImpl.cpp:1342 | SetLocalDescription
[task 2019-03-19T10:07:49.889Z] 10:07:49 INFO - PID 8392 | 0.149462 | 0.053684 | Set Remote Description | PeerConnectionImpl.cpp:1444 | SetRemoteDescription
[task 2019-03-19T10:07:49.890Z] 10:07:49 INFO - PID 8392 | 0.205900 | 0.056438 | Ice gathering state: gathering | PeerConnectionImpl.cpp:2670 | IceGatheringStateChange
[task 2019-03-19T10:07:49.895Z] 10:07:49 INFO - PID 8392 | 0.216373 | 0.010473 | Ice gathering state: complete | PeerConnectionImpl.cpp:2673 | IceGatheringStateChange
[task 2019-03-19T10:07:49.896Z] 10:07:49 INFO - PID 8392 | 0.248403 | 0.032030 | Add Ice Candidate | PeerConnectionImpl.cpp:1614 | AddIceCandidate
[task 2019-03-19T10:07:49.897Z] 10:07:49 INFO - PID 8392 | 0.252387 | 0.003984 | Add Ice Candidate | PeerConnectionImpl.cpp:1614 | AddIceCandidate
[task 2019-03-19T10:07:49.897Z] 10:07:49 INFO - PID 8392 | 0.256775 | 0.004388 | Add Ice Candidate | PeerConnectionImpl.cpp:1614 | AddIceCandidate
[task 2019-03-19T10:07:49.898Z] 10:07:49 INFO - PID 8392 | 0.260095 | 0.003320 | Add Ice Candidate | PeerConnectionImpl.cpp:1614 | AddIceCandidate
[task 2019-03-19T10:07:49.899Z] 10:07:49 INFO - PID 8392 | 0.273430 | 0.013335 | Ice state: checking | PeerConnectionImpl.cpp:2625 | IceConnectionStateChange
[task 2019-03-19T10:07:49.900Z] 10:07:49 INFO - PID 8392 | 0.274778 | 0.001348 | Ice state: connected | PeerConnectionImpl.cpp:2628 | IceConnectionStateChange
[task 2019-03-19T10:07:49.901Z] 10:07:49 INFO - PID 8392 | 0.847823 | 0.573045 | Destructor Invoked | PeerConnectionImpl.cpp:347 | ~PeerConnectionImpl
[task 2019-03-19T10:07:49.902Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: E/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:368: PeerConnectionCtx is already gone. Ignoring...
[task 2019-03-19T10:07:49.902Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:372: ~PeerConnectionImpl: PeerConnectionImpl destructor invoked for 6f04a6a42f94e55b
[task 2019-03-19T10:07:49.903Z] 10:07:49 INFO - PID 8392 | Timecard created 1552990069.070629
[task 2019-03-19T10:07:49.904Z] 10:07:49 INFO - PID 8392 | Timestamp | Delta | Event | File | Function
[task 2019-03-19T10:07:49.911Z] 10:07:49 INFO - PID 8392 | ======================================================================================================================
[task 2019-03-19T10:07:49.912Z] 10:07:49 INFO - PID 8392 | 0.000042 | 0.000042 | Constructor Completed | PeerConnectionImpl.cpp:338 | PeerConnectionImpl
[task 2019-03-19T10:07:49.912Z] 10:07:49 INFO - PID 8392 | 0.002542 | 0.002500 | Initializing PC Ctx | PeerConnectionImpl.cpp:465 | Initialize
[task 2019-03-19T10:07:49.912Z] 10:07:49 INFO - PID 8392 | 0.076362 | 0.073820 | Set Remote Description | PeerConnectionImpl.cpp:1444 | SetRemoteDescription
[task 2019-03-19T10:07:49.913Z] 10:07:49 INFO - PID 8392 | 0.089440 | 0.013078 | Create Answer | PeerConnectionImpl.cpp:1296 | CreateAnswer
[task 2019-03-19T10:07:49.913Z] 10:07:49 INFO - PID 8392 | 0.092259 | 0.002819 | Set Local Description | PeerConnectionImpl.cpp:1342 | SetLocalDescription
[task 2019-03-19T10:07:49.914Z] 10:07:49 INFO - PID 8392 | 0.161100 | 0.068841 | Ice gathering state: gathering | PeerConnectionImpl.cpp:2670 | IceGatheringStateChange
[task 2019-03-19T10:07:49.914Z] 10:07:49 INFO - PID 8392 | 0.167494 | 0.006394 | Ice gathering state: complete | PeerConnectionImpl.cpp:2673 | IceGatheringStateChange
[task 2019-03-19T10:07:49.915Z] 10:07:49 INFO - PID 8392 | 0.173754 | 0.006260 | Add Ice Candidate | PeerConnectionImpl.cpp:1614 | AddIceCandidate
[task 2019-03-19T10:07:49.915Z] 10:07:49 INFO - PID 8392 | 0.178612 | 0.004858 | Add Ice Candidate | PeerConnectionImpl.cpp:1614 | AddIceCandidate
[task 2019-03-19T10:07:49.915Z] 10:07:49 INFO - PID 8392 | 0.183078 | 0.004466 | Add Ice Candidate | PeerConnectionImpl.cpp:1614 | AddIceCandidate
[task 2019-03-19T10:07:49.916Z] 10:07:49 INFO - PID 8392 | 0.189073 | 0.005995 | Add Ice Candidate | PeerConnectionImpl.cpp:1614 | AddIceCandidate
[task 2019-03-19T10:07:49.916Z] 10:07:49 INFO - PID 8392 | 0.223512 | 0.034439 | Ice state: checking | PeerConnectionImpl.cpp:2625 | IceConnectionStateChange
[task 2019-03-19T10:07:49.916Z] 10:07:49 INFO - PID 8392 | 0.224790 | 0.001278 | Ice state: connected | PeerConnectionImpl.cpp:2628 | IceConnectionStateChange
[task 2019-03-19T10:07:49.917Z] 10:07:49 INFO - PID 8392 | 0.799119 | 0.574329 | Destructor Invoked | PeerConnectionImpl.cpp:347 | ~PeerConnectionImpl
[task 2019-03-19T10:07:49.918Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: E/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:368: PeerConnectionCtx is already gone. Ignoring...
[task 2019-03-19T10:07:49.919Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:372: ~PeerConnectionImpl: PeerConnectionImpl destructor invoked for 9ae82075615f08e5
[task 2019-03-19T10:07:49.937Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: D/DataChannel 0x60f0000a0720: Close()ing 0x60f0000a0630
[task 2019-03-19T10:07:49.938Z] 10:07:49 INFO - PID 8392 | [Child 13621: Main Thread]: D/DataChannel 0x60f0000cd270: Close()ing 0x60f0001ee6e0
[task 2019-03-19T10:07:50.790Z] 10:07:50 INFO - PID 8392 | -----------------------------------------------------
[task 2019-03-19T10:07:50.790Z] 10:07:50 INFO - PID 8392 | Suppressions used:
[task 2019-03-19T10:07:50.790Z] 10:07:50 INFO - PID 8392 | count bytes template
[task 2019-03-19T10:07:50.790Z] 10:07:50 INFO - PID 8392 | 30 928 nsComponentManagerImpl
[task 2019-03-19T10:07:50.790Z] 10:07:50 INFO - PID 8392 | 2 288 libfontconfig.so
[task 2019-03-19T10:07:50.790Z] 10:07:50 INFO - PID 8392 | -----------------------------------------------------
[task 2019-03-19T10:07:50.940Z] 10:07:50 INFO - PID 8392 | -----------------------------------------------------
[task 2019-03-19T10:07:50.940Z] 10:07:50 INFO - PID 8392 | Suppressions used:
[task 2019-03-19T10:07:50.940Z] 10:07:50 INFO - PID 8392 | count bytes template
[task 2019-03-19T10:07:50.941Z] 10:07:50 INFO - PID 8392 | 30 928 nsComponentManagerImpl
[task 2019-03-19T10:07:50.941Z] 10:07:50 INFO - PID 8392 | 611 17713 libfontconfig.so
[task 2019-03-19T10:07:50.941Z] 10:07:50 INFO - PID 8392 | 1 29 libglib-2.0.so
[task 2019-03-19T10:07:50.941Z] 10:07:50 INFO - PID 8392 | -----------------------------------------------------
[task 2019-03-19T10:07:51.179Z] 10:07:51 INFO - PID 8392 | -----------------------------------------------------
[task 2019-03-19T10:07:51.179Z] 10:07:51 INFO - PID 8392 | Suppressions used:
[task 2019-03-19T10:07:51.180Z] 10:07:51 INFO - PID 8392 | count bytes template
[task 2019-03-19T10:07:51.180Z] 10:07:51 INFO - PID 8392 | 30 928 nsComponentManagerImpl
[task 2019-03-19T10:07:51.180Z] 10:07:51 INFO - PID 8392 | 611 17713 libfontconfig.so
[task 2019-03-19T10:07:51.181Z] 10:07:51 INFO - PID 8392 | 2 65568 nr_reg_local_init
[task 2019-03-19T10:07:51.182Z] 10:07:51 INFO - PID 8392 | 195 18592 r_log_register
[task 2019-03-19T10:07:51.182Z] 10:07:51 INFO - PID 8392 | 60 2761 nr_reg_set
[task 2019-03-19T10:07:51.183Z] 10:07:51 INFO - PID 8392 | 1 29 libglib-2.0.so
[task 2019-03-19T10:07:51.184Z] 10:07:51 INFO - PID 8392 | -----------------------------------------------------
[task 2019-03-19T10:07:51.455Z] 10:07:51 INFO - PID 8392 | -----------------------------------------------------
[task 2019-03-19T10:07:51.455Z] 10:07:51 INFO - PID 8392 | Suppressions used:
[task 2019-03-19T10:07:51.455Z] 10:07:51 INFO - PID 8392 | count bytes template
[task 2019-03-19T10:07:51.455Z] 10:07:51 INFO - PID 8392 | 30 928 nsComponentManagerImpl
[task 2019-03-19T10:07:51.455Z] 10:07:51 INFO - PID 8392 | 611 17713 libfontconfig.so
[task 2019-03-19T10:07:51.455Z] 10:07:51 INFO - PID 8392 | 1 29 libglib-2.0.so
[task 2019-03-19T10:07:51.455Z] 10:07:51 INFO - PID 8392 | -----------------------------------------------------
[task 2019-03-19T10:07:52.787Z] 10:07:52 INFO - PID 8392 | =================================================================
[task 2019-03-19T10:07:52.788Z] 10:07:52 INFO - PID 8392 | LeakSanitizer: detected memory leaks
[task 2019-03-19T10:07:52.788Z] 10:07:52 INFO - PID 8392 | Direct leak of 336 byte(s) in 2 object(s) allocated from:
[task 2019-03-19T10:07:52.789Z] 10:07:52 INFO - PID 8392 | #0 0x55e806315983 in __interceptor_malloc /builds/worker/workspace/moz-toolchain/src/llvm/projects/compiler-rt/lib/asan/asan_malloc_linux.cc:146:3
[task 2019-03-19T10:07:52.789Z] 10:07:52 INFO - PID 8392 | #1 0x55e80634a1ad in moz_xmalloc /builds/worker/workspace/build/src/memory/mozalloc/mozalloc.cpp:68:15
[task 2019-03-19T10:07:52.790Z] 10:07:52 INFO - PID 8392 | #2 0x7fc9de73aacf in operator new /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/mozalloc.h:131:10
[task 2019-03-19T10:07:52.791Z] 10:07:52 INFO - PID 8392 | #3 0x7fc9de73aacf in mozilla::net::nsUDPSocket::SendWithAddress(mozilla::net::NetAddr const, unsigned char const*, unsigned int, unsigned int*) /builds/worker/workspace/build/src/netwerk/base/nsUDPSocket.cpp:1161
[task 2019-03-19T10:07:52.792Z] 10:07:52 INFO - PID 8392 | #4 0x7fc9e5a5b139 in mozilla::dom::UDPSocketParent::Send(nsTArray<unsigned char> const&, UDPSocketAddr const&) /builds/worker/workspace/build/src/dom/network/UDPSocketParent.cpp:382:21
[task 2019-03-19T10:07:52.800Z] 10:07:52 INFO - PID 8392 | #5 0x7fc9e5a5ace6 in mozilla::dom::UDPSocketParent::RecvOutgoingData(UDPData const&, UDPSocketAddr const&) /builds/worker/workspace/build/src/dom/network/UDPSocketParent.cpp:356:7
[task 2019-03-19T10:07:52.800Z] 10:07:52 INFO - PID 8392 | #6 0x7fc9dfb1671f in mozilla::net::PUDPSocketParent::OnMessageReceived(IPC::Message const&) /builds/worker/workspace/build/src/obj-firefox/ipc/ipdl/PUDPSocketParent.cpp:343:73
[task 2019-03-19T10:07:52.800Z] 10:07:52 INFO - PID 8392 | #7 0x7fc9dfc4520f in mozilla::ipc::PBackgroundParent::OnMessageReceived(IPC::Message const&) /builds/worker/workspace/build/src/obj-firefox/ipc/ipdl/PBackgroundParent.cpp:1506:28
[task 2019-03-19T10:07:52.800Z] 10:07:52 INFO - PID 8392 | #8 0x7fc9df405709 in mozilla::ipc::MessageChannel::DispatchAsyncMessage(IPC::Message const&) /builds/worker/workspace/build/src/ipc/glue/MessageChannel.cpp:2151:21
[task 2019-03-19T10:07:52.800Z] 10:07:52 INFO - PID 8392 | #9 0x7fc9df4028ac in mozilla::ipc::MessageChannel::DispatchMessage(IPC::Message&&) /builds/worker/workspace/build/src/ipc/glue/MessageChannel.cpp:2078:9
[task 2019-03-19T10:07:52.800Z] 10:07:52 INFO - PID 8392 | #10 0x7fc9df40422b in mozilla::ipc::MessageChannel::RunMessage(mozilla::ipc::MessageChannel::MessageTask&) /builds/worker/workspace/build/src/ipc/glue/MessageChannel.cpp:1937:3
[task 2019-03-19T10:07:52.800Z] 10:07:52 INFO - PID 8392 | #11 0x7fc9df404797 in mozilla::ipc::MessageChannel::MessageTask::Run() /builds/worker/workspace/build/src/ipc/glue/MessageChannel.cpp:1968:13
[task 2019-03-19T10:07:52.800Z] 10:07:52 INFO - PID 8392 | #12 0x7fc9de456af9 in nsThread::ProcessNextEvent(bool, bool*) /builds/worker/workspace/build/src/xpcom/threads/nsThread.cpp:1179:14
[task 2019-03-19T10:07:52.801Z] 10:07:52 INFO - PID 8392 | #13 0x7fc9de45d298 in NS_ProcessNextEvent(nsIThread*, bool) /builds/worker/workspace/build/src/xpcom/threads/nsThreadUtils.cpp:482:10
[task 2019-03-19T10:07:52.801Z] 10:07:52 INFO - PID 8392 | #14 0x7fc9df40daca in mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) /builds/worker/workspace/build/src/ipc/glue/MessagePump.cpp:303:20
[task 2019-03-19T10:07:52.801Z] 10:07:52 INFO - PID 8392 | #15 0x7fc9df33f59f in RunInternal /builds/worker/workspace/build/src/ipc/chromium/src/base/message_loop.cc:315:10
[task 2019-03-19T10:07:52.801Z] 10:07:52 INFO - PID 8392 | #16 0x7fc9df33f59f in RunHandler /builds/worker/workspace/build/src/ipc/chromium/src/base/message_loop.cc:308
[task 2019-03-19T10:07:52.801Z] 10:07:52 INFO - PID 8392 | #17 0x7fc9df33f59f in MessageLoop::Run() /builds/worker/workspace/build/src/ipc/chromium/src/base/message_loop.cc:290
[task 2019-03-19T10:07:52.801Z] 10:07:52 INFO - PID 8392 | #18 0x7fc9de450aea in nsThread::ThreadFunc(void*) /builds/worker/workspace/build/src/xpcom/threads/nsThread.cpp:454:11
[task 2019-03-19T10:07:52.802Z] 10:07:52 INFO - PID 8392 | #19 0x7fc9fb8d55ad in _pt_root /builds/worker/workspace/build/src/nsprpub/pr/src/pthreads/ptthread.c:201:5
[task 2019-03-19T10:07:52.803Z] 10:07:52 INFO - PID 8392 | #20 0x7fc9ff6206b9 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x76b9)
[task 2019-03-19T10:07:52.810Z] 10:07:52 INFO - PID 8392 | Indirect leak of 154 byte(s) in 2 object(s) allocated from:
[task 2019-03-19T10:07:52.811Z] 10:07:52 INFO - PID 8392 | #0 0x55e806315983 in __interceptor_malloc /builds/worker/workspace/moz-toolchain/src/llvm/projects/compiler-rt/lib/asan/asan_malloc_linux.cc:146:3
[task 2019-03-19T10:07:52.812Z] 10:07:52 INFO - PID 8392 | #1 0x7fc9de38d95d in Malloc /builds/worker/workspace/build/src/obj-firefox/dist/include/nsTArray.h:189:46
[task 2019-03-19T10:07:52.813Z] 10:07:52 INFO - PID 8392 | #2 0x7fc9de38d95d in nsTArrayFallibleAllocator::ResultTypeProxy nsTArray_base<nsTArrayFallibleAllocator, nsTArray_CopyWithMemutils>::EnsureCapacity<nsTArrayFallibleAllocator>(unsigned long, unsigned long) /builds/worker/workspace/build/src/obj-firefox/dist/include/nsTArray-inl.h:144
[task 2019-03-19T10:07:52.813Z] 10:07:52 INFO - PID 8392 | #3 0x7fc9de750235 in unsigned char* nsTArray_Impl<unsigned char, nsTArrayFallibleAllocator>::ReplaceElementsAt<unsigned char, nsTArrayFallibleAllocator>(unsigned long, unsigned long, unsigned char const*, unsigned long) /builds/worker/workspace/build/src/obj-firefox/dist/include/nsTArray.h:2208:47
[task 2019-03-19T10:07:52.814Z] 10:07:52 INFO - PID 8392 | #4 0x7fc9de73aaaa in InsertElementsAt<unsigned char, nsTArrayFallibleAllocator> /builds/worker/workspace/build/src/obj-firefox/dist/include/nsTArray.h:1404:12
[task 2019-03-19T10:07:52.815Z] 10:07:52 INFO - PID 8392 | #5 0x7fc9de73aaaa in InsertElementsAt<unsigned char> /builds/worker/workspace/build/src/obj-firefox/dist/include/nsTArray.h:1413
[task 2019-03-19T10:07:52.816Z] 10:07:52 INFO - PID 8392 | #6 0x7fc9de73aaaa in mozilla::net::nsUDPSocket::SendWithAddress(mozilla::net::NetAddr const*, unsigned char const*, unsigned int, unsigned int*) /builds/worker/workspace/build/src/netwerk/base/nsUDPSocket.cpp:1156
[task 2019-03-19T10:07:52.821Z] 10:07:52 INFO - PID 8392 | #7 0x7fc9e5a5b139 in mozilla::dom::UDPSocketParent::Send(nsTArray<unsigned char> const&, UDPSocketAddr const&) /builds/worker/workspace/build/src/dom/network/UDPSocketParent.cpp:382:21
[task 2019-03-19T10:07:52.822Z] 10:07:52 INFO - PID 8392 | #8 0x7fc9e5a5ace6 in mozilla::dom::UDPSocketParent::RecvOutgoingData(UDPData const&, UDPSocketAddr const&) /builds/worker/workspace/build/src/dom/network/UDPSocketParent.cpp:356:7
[task 2019-03-19T10:07:52.823Z] 10:07:52 INFO - PID 8392 | #9 0x7fc9dfb1671f in mozilla::net::PUDPSocketParent::OnMessageReceived(IPC::Message const&) /builds/worker/workspace/build/src/obj-firefox/ipc/ipdl/PUDPSocketParent.cpp:343:73
[task 2019-03-19T10:07:52.823Z] 10:07:52 INFO - PID 8392 | #10 0x7fc9dfc4520f in mozilla::ipc::PBackgroundParent::OnMessageReceived(IPC::Message const&) /builds/worker/workspace/build/src/obj-firefox/ipc/ipdl/PBackgroundParent.cpp:1506:28
[task 2019-03-19T10:07:52.823Z] 10:07:52 INFO - PID 8392 | #11 0x7fc9df405709 in mozilla::ipc::MessageChannel::DispatchAsyncMessage(IPC::Message const&) /builds/worker/workspace/build/src/ipc/glue/MessageChannel.cpp:2151:21
[task 2019-03-19T10:07:52.823Z] 10:07:52 INFO - PID 8392 | #12 0x7fc9df4028ac in mozilla::ipc::MessageChannel::DispatchMessage(IPC::Message&&) /builds/worker/workspace/build/src/ipc/glue/MessageChannel.cpp:2078:9
[task 2019-03-19T10:07:52.823Z] 10:07:52 INFO - PID 8392 | #13 0x7fc9df40422b in mozilla::ipc::MessageChannel::RunMessage(mozilla::ipc::MessageChannel::MessageTask&) /builds/worker/workspace/build/src/ipc/glue/MessageChannel.cpp:1937:3
[task 2019-03-19T10:07:52.824Z] 10:07:52 INFO - PID 8392 | #14 0x7fc9df404797 in mozilla::ipc::MessageChannel::MessageTask::Run() /builds/worker/workspace/build/src/ipc/glue/MessageChannel.cpp:1968:13
[task 2019-03-19T10:07:52.824Z] 10:07:52 INFO - PID 8392 | #15 0x7fc9de456af9 in nsThread::ProcessNextEvent(bool, bool*) /builds/worker/workspace/build/src/xpcom/threads/nsThread.cpp:1179:14
[task 2019-03-19T10:07:52.824Z] 10:07:52 INFO - PID 8392 | #16 0x7fc9de45d298 in NS_ProcessNextEvent(nsIThread*, bool) /builds/worker/workspace/build/src/xpcom/threads/nsThreadUtils.cpp:482:10
[task 2019-03-19T10:07:52.824Z] 10:07:52 INFO - PID 8392 | #17 0x7fc9df40daca in mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) /builds/worker/workspace/build/src/ipc/glue/MessagePump.cpp:303:20
[task 2019-03-19T10:07:52.824Z] 10:07:52 INFO - PID 8392 | #18 0x7fc9df33f59f in RunInternal /builds/worker/workspace/build/src/ipc/chromium/src/base/message_loop.cc:315:10
[task 2019-03-19T10:07:52.824Z] 10:07:52 INFO - PID 8392 | #19 0x7fc9df33f59f in RunHandler /builds/worker/workspace/build/src/ipc/chromium/src/base/message_loop.cc:308
[task 2019-03-19T10:07:52.825Z] 10:07:52 INFO - PID 8392 | #20 0x7fc9df33f59f in MessageLoop::Run() /builds/worker/workspace/build/src/ipc/chromium/src/base/message_loop.cc:290
[task 2019-03-19T10:07:52.825Z] 10:07:52 INFO - PID 8392 | #21 0x7fc9de450aea in nsThread::ThreadFunc(void*) /builds/worker/workspace/build/src/xpcom/threads/nsThread.cpp:454:11
[task 2019-03-19T10:07:52.825Z] 10:07:52 INFO - PID 8392 | #22 0x7fc9fb8d55ad in _pt_root /builds/worker/workspace/build/src/nsprpub/pr/src/pthreads/ptthread.c:201:5
[task 2019-03-19T10:07:52.825Z] 10:07:52 INFO - PID 8392 | #23 0x7fc9ff6206b9 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x76b9)
[task 2019-03-19T10:07:52.825Z] 10:07:52 INFO - PID 8392 | -----------------------------------------------------
[task 2019-03-19T10:07:52.826Z] 10:07:52 INFO - PID 8392 | Suppressions used:
[task 2019-03-19T10:07:52.826Z] 10:07:52 INFO - PID 8392 | count bytes template
[task 2019-03-19T10:07:52.826Z] 10:07:52 INFO - PID 8392 | 27 824 nsComponentManagerImpl
[task 2019-03-19T10:07:52.826Z] 10:07:52 INFO - PID 8392 | 4 832 mozJSComponentLoader::LoadModule
[task 2019-03-19T10:07:52.826Z] 10:07:52 INFO - PID 8392 | 611 17509 libfontconfig.so
[task 2019-03-19T10:07:52.827Z] 10:07:52 INFO - PID 8392 | 134 5896 _PR_Getfd
[task 2019-03-19T10:07:52.827Z] 10:07:52 INFO - PID 8392 | 1 29 libglib-2.0.so
[task 2019-03-19T10:07:52.827Z] 10:07:52 INFO - PID 8392 | -----------------------------------------------------
[task 2019-03-19T10:07:52.942Z] 10:07:52 INFO - Browser exited with return code 0
[task 2019-03-19T10:07:52.943Z] 10:07:52 INFO - PROCESS LEAKS None
[task 2019-03-19T10:07:52.943Z] 10:07:52 INFO - ERROR | LeakSanitizer | SUMMARY: AddressSanitizer: 490 byte(s) leaked in 4 allocation(s).
[task 2019-03-19T10:07:52.943Z] 10:07:52 INFO - LeakSanitizer | To show the addresses of leaked objects add report_objects=1 to LSAN_OPTIONS
[task 2019-03-19T10:07:52.943Z] 10:07:52 INFO - This can be done in testing/mozbase/mozrunner/mozrunner/utils.py
[task 2019-03-19T10:07:52.944Z] 10:07:52 INFO - Allowed depth was 4
[task 2019-03-19T10:07:52.944Z] 10:07:52 INFO - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at mozilla::net::nsUDPSocket::SendWithAddress, mozilla::dom::UDPSocketParent::Send, mozilla::dom::UDPSocketParent::RecvOutgoingData, mozilla::net::PUDPSocketParent::OnMessageReceived
[task 2019-03-19T10:07:52.944Z] 10:07:52 INFO - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at Malloc, nsTArray_base, nsTArray_Impl, InsertElementsAt
[task 2019-03-19T10:07:52.945Z] 10:07:52 INFO - Closing logging queue
[task 2019-03-19T10:07:52.945Z] 10:07:52 INFO - queue closed
[task 2019-03-19T10:07:52.946Z] 10:07:52 INFO - INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2019-03-19T10:07:52.962Z] 10:07:52 INFO - LSan enabled.
[task 2019-03-19T10:07:52.962Z] 10:07:52 INFO - LSan using suppression file /builds/worker/workspace/build/tests/web-platform/prefs/lsan_suppressions.txt
[task 2019-03-19T10:07:52.962Z] 10:07:52 INFO - INFO | runtests.py | ASan running in default memory configuration
[task 2019-03-19T10:07:52.978Z] 10:07:52 INFO - Setting up ssl
[task 2019-03-19T10:07:53.019Z] 10:07:53 INFO - certutil |
[task 2019-03-19T10:07:53.075Z] 10:07:53 INFO - certutil |
[task 2019-03-19T10:07:53.111Z] 10:07:53 INFO - certutil |
[task 2019-03-19T10:07:53.111Z] 10:07:53 INFO - Certificate Nickname Trust Attributes
[task 2019-03-19T10:07:53.111Z] 10:07:53 INFO - SSL,S/MIME,JAR/XPI
[task 2019-03-19T10:07:53.111Z] 10:07:53 INFO -
[task 2019-03-19T10:07:53.111Z] 10:07:53 INFO - web-platform-tests CT,,
[task 2019-03-19T10:07:53.111Z] 10:07:53 INFO -
[task 2019-03-19T10:07:53.127Z] 10:07:53 INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox --marionette about:blank -profile /tmp/tmphar0QU.mozrunner
[task 2019-03-19T10:07:53.143Z] 10:07:53 INFO - Starting runner
[task 2019-03-19T10:07:54.652Z] 10:07:54 INFO - PID 13744 | 1552990074641 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: mozillaAddons
[task 2019-03-19T10:07:54.652Z] 10:07:54 INFO - PID 13744 | 1552990074643 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: resource://pdf.js/
[task 2019-03-19T10:07:54.652Z] 10:07:54 INFO - PID 13744 | 1552990074643 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: about:reader*
[task 2019-03-19T10:08:00.727Z] 10:08:00 INFO - PID 13744 | 1552990080725 Marionette INFO Listening on port 2828
Description
•