Closed
Bug 1683890
Opened 5 years ago
Closed 5 years ago
Intermittent TEST-UNEXPECTED-PASS | /webrtc/RTCPeerConnection-ondatachannel.html | Data channel event should fire when new data channel is announced to the remote peer - expected TIMEOUT
Categories
(Core :: WebRTC, defect, P5)
Core
WebRTC
Tracking
()
RESOLVED
INCOMPLETE
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure)
Filed by: smolnar [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=325203957&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Vmy-GiWnQHCoK3SRaD48gw/runs/0/artifacts/public/logs/live_backing.log
"INFO - TEST-START | /webrtc/RTCPeerConnection-ondatachannel.html
[task 2020-12-22T11:35:28.599Z] 11:35:28 INFO - Clearing pref media.navigator.permission.disabled
[task 2020-12-22T11:35:28.600Z] 11:35:28 INFO - Clearing pref media.navigator.streams.fake
[task 2020-12-22T11:35:28.602Z] 11:35:28 INFO - Clearing pref privacy.resistFingerprinting.reduceTimerPrecision.jitter
[task 2020-12-22T11:35:28.606Z] 11:35:28 INFO - Clearing pref privacy.reduceTimerPrecision
[task 2020-12-22T11:35:28.609Z] 11:35:28 INFO - Clearing pref media.peerconnection.ice.trickle_grace_period
[task 2020-12-22T11:35:28.616Z] 11:35:28 INFO - Setting pref media.navigator.permission.disabled (true)
[task 2020-12-22T11:35:28.624Z] 11:35:28 INFO - Setting pref media.navigator.streams.fake (true)
[task 2020-12-22T11:35:28.663Z] 11:35:28 INFO - Setting pref privacy.resistFingerprinting.reduceTimerPrecision.jitter (false)
[task 2020-12-22T11:35:28.671Z] 11:35:28 INFO - Setting pref privacy.reduceTimerPrecision (false)
[task 2020-12-22T11:35:28.679Z] 11:35:28 INFO - Setting pref media.peerconnection.ice.trickle_grace_period (10000)
[task 2020-12-22T11:35:28.683Z] 11:35:28 INFO - Closing window 47244640257
[task 2020-12-22T11:35:28.790Z] 11:35:28 INFO - PID 2344 | [Child 8136: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:325: PeerConnectionImpl: PeerConnectionImpl constructor for
[task 2020-12-22T11:35:28.791Z] 11:35:28 INFO - PID 2344 | (unknown/INFO) insert '' (registry) succeeded:
[task 2020-12-22T11:35:28.792Z] 11:35:28 INFO - PID 2344 | (registry/INFO) Initialized registry
[task 2020-12-22T11:35:28.795Z] 11:35:28 INFO - PID 2344 | [Parent 3708: Socket Thread]: D/mtransport NrIceCtx static call to find local stun addresses
[task 2020-12-22T11:35:28.796Z] 11:35:28 INFO - PID 2344 | [Child 8136: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:325: PeerConnectionImpl: PeerConnectionImpl constructor for
[task 2020-12-22T11:35:28.797Z] 11:35:28 INFO - PID 2344 | [Parent 3708: Socket Thread]: D/mtransport NrIceCtx static call to find local stun addresses
[task 2020-12-22T11:35:28.799Z] 11:35:28 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel Maximum message size (outgoing data): 2147483637 (set=no, enforced=yes)
[task 2020-12-22T11:35:28.800Z] 11:35:28 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel sctp_init
[task 2020-12-22T11:35:28.801Z] 11:35:28 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel Setting number of SCTP streams to 256, was 10/2048
[task 2020-12-22T11:35:28.802Z] 11:35:28 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel DC Open: label fire-me!/, type 0, inorder 1, prValue 0, listener 0000000000000000, context 0000000000000000, external: false, stream 65535
[task 2020-12-22T11:35:28.803Z] 11:35:28 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel Inserting channel 65535 : 000001E4CE3493C0
[task 2020-12-22T11:35:28.804Z] 11:35:28 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel Queuing channel 000001E4CE3493C0 (65535) to finish open
[task 2020-12-22T11:35:28.806Z] 11:35:28 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel Init: origin = http://web-platform.test:8000
[task 2020-12-22T11:35:28.807Z] 11:35:28 INFO - PID 2344 | [Child 8136: Main Thread]: I/signaling [main|PeerConnectionMedia] PeerConnectionMedia.cpp:75: OnStunAddrsAvailable: receiving (3) stun addrs
[task 2020-12-22T11:35:28.808Z] 11:35:28 INFO - PID 2344 | [Child 8136: Main Thread]: I/signaling [main|PeerConnectionMedia] PeerConnectionMedia.cpp:75: OnStunAddrsAvailable: receiving (3) stun addrs
[task 2020-12-22T11:35:28.809Z] 11:35:28 INFO - PID 2344 | [Child 8136: Socket Thread]: D/DataChannel Registered 0000000000000001 within the SCTP stack.
[task 2020-12-22T11:35:28.810Z] 11:35:28 INFO - PID 2344 | (registry/INFO) insert 'ice' (registry) succeeded: ice
[task 2020-12-22T11:35:28.811Z] 11:35:28 INFO - PID 2344 | (registry/INFO) insert 'ice.pref' (registry) succeeded: ice.pref
[task 2020-12-22T11:35:28.812Z] 11:35:28 INFO - PID 2344 | (registry/INFO) insert 'ice.pref.type' (registry) succeeded: ice.pref.type
[task 2020-12-22T11:35:28.813Z] 11:35:28 INFO - PID 2344 | (registry/INFO) insert 'ice.pref.type.srv_rflx' (UCHAR) succeeded: 0x64
[task 2020-12-22T11:35:28.815Z] 11:35:28 INFO - PID 2344 | (registry/INFO) insert 'ice.pref.type.peer_rflx' (UCHAR) succeeded: 0x6e
[task 2020-12-22T11:35:28.816Z] 11:35:28 INFO - PID 2344 | (registry/INFO) insert 'ice.pref.type.host' (UCHAR) succeeded: 0x7e
[task 2020-12-22T11:35:28.817Z] 11:35:28 INFO - PID 2344 | (registry/INFO) insert 'ice.pref.type.relayed' (UCHAR) succeeded: 0x05
[task 2020-12-22T11:35:28.818Z] 11:35:28 INFO - PID 2344 | (registry/INFO) insert 'ice.pref.type.srv_rflx_tcp' (UCHAR) succeeded: 0x63
[task 2020-12-22T11:35:28.819Z] 11:35:28 INFO - PID 2344 | (registry/INFO) insert 'ice.pref.type.peer_rflx_tcp' (U[Child 8136: Main Thread]: I/signaling [main|sdp_config] sdp_config.c:86: SDP: Initialized config pointer: 000001E4CDDE9430
[task 2020-12-22T11:35:28.820Z] 11:35:28 INFO - PID 2344 | CHAR) succeeded: 0x6d
[task 2020-12-22T11:35:28.821Z] 11:35:28 INFO - PID 2344 | (registry/INFO) insert 'ice.pref.type.host_tcp' (UCHAR) succeeded: 0x7d
...
INFO - PID 2344 | [Child 8136: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2095: CloseInt: Destroying DataChannelConnection 000001E4CE708800 for {2b649422-4a14-49f9-80e3-422a73dcb66f}
[task 2020-12-22T11:35:31.550Z] 11:35:31 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel Destroying DataChannelConnection 000001E4CE708800
[task 2020-12-22T11:35:31.551Z] 11:35:31 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel Closing all channels (connection 000001E4CE708800)
[task 2020-12-22T11:35:31.552Z] 11:35:31 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel DataChannelConnection labeled transport_0 (000001E4CE708800) switching connection state OPEN -> CLOSED
[task 2020-12-22T11:35:31.553Z] 11:35:31 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel Connection 000001E4CE708800/Channel 000001E4CE5D52E0: Closing stream 42
[task 2020-12-22T11:35:31.554Z] 11:35:31 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel Removing channel 42 : 000001E4CE5D52E0
[task 2020-12-22T11:35:31.556Z] 11:35:31 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel Connection 000001E4CE708800: Resetting outgoing stream 42
[task 2020-12-22T11:35:31.557Z] 11:35:31 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel DataChannelConnection labeled test(000001E4CE5D52E0) (stream 42) changing ready state OPEN -> CLOSING
[task 2020-12-22T11:35:31.558Z] 11:35:31 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel Destroying Data channel 42
[task 2020-12-22T11:35:31.559Z] 11:35:31 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel Connection 000001E4CE708800: Sending outgoing stream reset for 1 streams
[task 2020-12-22T11:35:31.560Z] 11:35:31 INFO - PID 2344 | [Child 8136: Socket Thread]: D/DataChannel Deregistered 000000000000000F from the SCTP stack.
[task 2020-12-22T11:35:31.561Z] 11:35:31 INFO - PID 2344 | [Child 8136: Main Thread]: E/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2758: GetStats: Found no pipelines matching selector.
[task 2020-12-22T11:35:31.562Z] 11:35:31 INFO - PID 2344 | [Child 8136: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2089: CloseInt: Closing PeerConnectionImpl {9fe8643e-106d-4243-a090-08ca9ceace8c}; ending call
[task 2020-12-22T11:35:31.564Z] 11:35:31 INFO - PID 2344 | [Child 8136: Main Thread]: I/jsep [{9fe8643e-106d-4243-a090-08ca9ceace8c} 1608636931030000 (id=49392123909 url=http://web-platform.test:8000/webrtc/RTCPeerConnect]: stable -> closed
[task 2020-12-22T11:35:31.565Z] 11:35:31 INFO - PID 2344 | [Child 8136: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2095: CloseInt: Destroying DataChannelConnection 000001E4CE703000 for {9fe8643e-106d-4243-a090-08ca9ceace8c}
[task 2020-12-22T11:35:31.567Z] 11:35:31 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel Destroying DataChannelConnection 000001E4CE703000
[task 2020-12-22T11:35:31.567Z] 11:35:31 INFO -
[task 2020-12-22T11:35:31.567Z] 11:35:31 INFO - TEST-UNEXPECTED-PASS | /webrtc/RTCPeerConnection-ondatachannel.html | Data channel event should fire when new data channel is announced to the remote peer - expected TIMEOUT
[task 2020-12-22T11:35:31.567Z] 11:35:31 INFO - TEST-INFO | expected TIMEOUT
[task 2020-12-22T11:35:31.568Z] 11:35:31 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel Closing all channels (connection 000001E4CE703000)
[task 2020-12-22T11:35:31.569Z] 11:35:31 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel DataChannelConnection labeled transport_0 (000001E4CE703000) switching connection state OPEN -> CLOSED
[task 2020-12-22T11:35:31.570Z] 11:35:31 INFO -
[task 2020-12-22T11:35:31.570Z] 11:35:31 INFO - TEST-UNEXPECTED-PASS | /webrtc/RTCPeerConnection-ondatachannel.html | Should be able to send data in a datachannel event handler - expected NOTRUN
[task 2020-12-22T11:35:31.570Z] 11:35:31 INFO - TEST-INFO | expected NOTRUN
[task 2020-12-22T11:35:31.571Z] 11:35:31 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel Connection 000001E4CE703000: Sending outgoing stream reset for 0 streams
[task 2020-12-22T11:35:31.572Z] 11:35:31 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel No streams to reset
[task 2020-12-22T11:35:31.573Z] 11:35:31 INFO -
[task 2020-12-22T11:35:31.573Z] 11:35:31 INFO - TEST-UNEXPECTED-PASS | /webrtc/RTCPeerConnection-ondatachannel.html | Open event should not be raised when closing the channel in the datachannel event - expected NOTRUN
[task 2020-12-22T11:35:31.573Z] 11:35:31 INFO - TEST-INFO | expected NOTRUN
[task 2020-12-22T11:35:31.574Z] 11:35:31 INFO - PID 2344 | [Child 8136: Socket Thread]: D/DataChannel Deregistered 0000000000000010 from the SCTP stack.
[task 2020-12-22T11:35:31.575Z] 11:35:31 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel DataChannelConnection labeled test(000001E4CE5D52E0) (stream 42) changing ready state CLOSING -> CLOSED
[task 2020-12-22T11:35:31.576Z] 11:35:31 INFO -
[task 2020-12-22T11:35:31.576Z] 11:35:31 INFO - TEST-UNEXPECTED-PASS | /webrtc/RTCPeerConnection-ondatachannel.html | Open event should be raised when closing the channel in the datachannel event after enqueuing a task - expected NOTRUN
[task 2020-12-22T11:35:31.576Z] 11:35:31 INFO - TEST-INFO | expected NOTRUN
[task 2020-12-22T11:35:31.577Z] 11:35:31 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel operator(): sending ON_CHANNEL_CLOSED for test/: 42
[task 2020-12-22T11:35:31.578Z] 11:35:31 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel 000001E4CE5747C0(000001E4CE5D52E0): OnChannelClosed - Dispatching
[task 2020-12-22T11:35:31.579Z] 11:35:31 INFO -
[task 2020-12-22T11:35:31.579Z] 11:35:31 INFO - TEST-UNEXPECTED-PASS | /webrtc/RTCPeerConnection-ondatachannel.html | Open event should not be raised when sending and immediately closing the channel in the datachannel event - expected NOTRUN
[task 2020-12-22T11:35:31.579Z] 11:35:31 INFO - TEST-INFO | expected NOTRUN
[task 2020-12-22T11:35:31.580Z] 11:35:31 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel Deleting DataChannelConnection 000001E4CE708800
[task 2020-12-22T11:35:31.581Z] 11:35:31 INFO -
[task 2020-12-22T11:35:31.581Z] 11:35:31 INFO - TEST-KNOWN-INTERMITTENT-PASS | /webrtc/RTCPeerConnection-ondatachannel.html | In-band negotiated channel created on remote peer should match the same configuration as local peer
[task 2020-12-22T11:35:31.582Z] 11:35:31 INFO - PID 2344 | [Child 8136: Main Thread]: D/DataChannel Deleting DataChannelConnection 000001E4CE703000
[task 2020-12-22T11:35:31.583Z] 11:35:31 INFO -
[task 2020-12-22T11:35:31.583Z] 11:35:31 INFO - TEST-KNOWN-INTERMITTENT-PASS | /webrtc/RTCPeerConnection-ondatachannel.html | In-band negotiated channel created on remote peer should match the same (default) configuration as local peer
[task 2020-12-22T11:35:31.584Z] 11:35:31 INFO -
[task 2020-12-22T11:35:31.584Z] 11:35:31 INFO - TEST-KNOWN-INTERMITTENT-PASS | /webrtc/RTCPeerConnection-ondatachannel.html | Negotiated channel should not fire datachannel event on remote peer
[task 2020-12-22T11:35:31.584Z] 11:35:31 INFO - TEST-KNOWN-INTERMITTENT-OK | /webrtc/RTCPeerConnection-ondatachannel.html | took 2986ms
[task 2020-12-22T11:35:31.587Z] 11:35:31 INFO - PID 2344 | 1608636931587 Marionette INFO Stopped listening on port 60782
[task 2020-12-22T11:35:31.958Z] 11:35:31 INFO - Browser exited with return code 0
[task 2020-12-22T11:35:31.958Z] 11:35:31 INFO - PROCESS LEAKS None
[task 2020-12-22T11:35:31.962Z] 11:35:31 INFO - Closing logging queue
[task 2020-12-22T11:35:31.962Z] 11:35:31 INFO - queue closed
[task 2020-12-22T11:35:32.039Z] 11:35:32 INFO - Application command: C:\Users\task_1608633963\build\application\firefox\firefox.exe -marionette about:blank --wait-for-browser -profile C:\Users\task_1608633963\AppData\Local\Temp\tmpy07jwh6l
[task 2020-12-22T11:35:32.042Z] 11:35:32 INFO - PID 5008 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new Error("", "(unknown module)"))
[task 2020-12-22T11:35:32.044Z] 11:35:32 INFO - PID 5008 | 1608636811199 Marionette INFO Listening on port 60814
[task 2020-12-22T11:35:32.044Z] 11:35:32 INFO - Starting runner
[task 2020-12-22T11:35:33.018Z] 11:35:33 INFO - TEST-START | /webrtc/RTCPeerConnection-onnegotiationneeded.html"```
| Comment hidden (Intermittent Failures Robot) |
|
||
Comment 2•5 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → INCOMPLETE
You need to log in
before you can comment on or make changes to this bug.
Description
•