1726084 - Intermittent dom/media/webrtc/tests/mochitests/test_dataChannel_hostnameObfuscation.html | PeerConnectionWrapper (pcRemote): legal ICE state transition from new to failed

Status: RESOLVED INCOMPLETE

(Core :: WebRTC: Audio/Video, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: malexandru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=348629155&repo=mozilla-beta
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ZlI5ATUGTgmEqZ5llzoerA/runs/0/artifacts/public/logs/live_backing.log

---

[task 2021-08-17T00:59:31.727Z] 00:59:31     INFO - TEST-START | dom/media/webrtc/tests/mochitests/test_dataChannel_hostnameObfuscation.html
[task 2021-08-17T00:59:31.733Z] 00:59:31     INFO - GECKO(9028) | TEST DEVICES: No test device found in media.audio_loopback_dev, using fake audio streams.
[task 2021-08-17T00:59:31.739Z] 00:59:31     INFO - GECKO(9028) | TEST DEVICES: No test device found in media.video_loopback_dev, using fake video streams.
[task 2021-08-17T00:59:31.744Z] 00:59:31     INFO - GECKO(9028) | Timecard created 1629161959.983000
[task 2021-08-17T00:59:31.750Z] 00:59:31     INFO - GECKO(9028) |  Timestamp   | Delta       | Event                          | File                         | Function
[task 2021-08-17T00:59:31.757Z] 00:59:31     INFO - GECKO(9028) | ======================================================================================================================
[task 2021-08-17T00:59:31.764Z] 00:59:31     INFO - GECKO(9028) |     0.000000 |    0.000000 | Constructor Completed          | PeerConnectionImpl.cpp:332   | PeerConnectionImpl
[task 2021-08-17T00:59:31.770Z] 00:59:31     INFO - GECKO(9028) |     0.002000 |    0.002000 | Initializing PC Ctx            | PeerConnectionImpl.cpp:450   | Initialize
[task 2021-08-17T00:59:31.777Z] 00:59:31     INFO - GECKO(9028) |     0.066000 |    0.064000 | Create Offer                   | PeerConnectionImpl.cpp:1212  | CreateOffer
[task 2021-08-17T00:59:31.783Z] 00:59:31     INFO - GECKO(9028) |     0.095000 |    0.029000 | Set Local Description          | PeerConnectionImpl.cpp:1281  | SetLocalDescription
[task 2021-08-17T00:59:31.790Z] 00:59:31     INFO - GECKO(9028) |     0.322000 |    0.227000 | Set Remote Description         | PeerConnectionImpl.cpp:1381  | SetRemoteDescription
[task 2021-08-17T00:59:31.797Z] 00:59:31     INFO - GECKO(9028) |     0.336000 |    0.014000 | Ice gathering state: gathering | PeerConnectionImpl.cpp:2537  | IceGatheringStateChange
[task 2021-08-17T00:59:31.804Z] 00:59:31     INFO - GECKO(9028) |     0.585000 |    0.249000 | Ice gathering state: complete  | PeerConnectionImpl.cpp:2540  | IceGatheringStateChange
[task 2021-08-17T00:59:31.810Z] 00:59:31     INFO - GECKO(9028) |     0.767000 |    0.182000 | Add Ice Candidate              | PeerConnectionImpl.cpp:1529  | AddIceCandidate
[task 2021-08-17T00:59:31.817Z] 00:59:31     INFO - GECKO(9028) |     0.813000 |    0.046000 | Add Ice Candidate              | PeerConnectionImpl.cpp:1529  | AddIceCandidate
[task 2021-08-17T00:59:31.824Z] 00:59:31     INFO - GECKO(9028) |     0.847000 |    0.034000 | Add Ice Candidate              | PeerConnectionImpl.cpp:1529  | AddIceCandidate
[task 2021-08-17T00:59:31.830Z] 00:59:31     INFO - GECKO(9028) |     1.189000 |    0.342000 | Ice state: checking            | PeerConnectionImpl.cpp:2481  | IceConnectionStateChange
[task 2021-08-17T00:59:31.837Z] 00:59:31     INFO - GECKO(9028) |     3.179000 |    1.990000 | Ice state: connected           | PeerConnectionImpl.cpp:2484  | IceConnectionStateChange
[task 2021-08-17T00:59:31.844Z] 00:59:31     INFO - GECKO(9028) |    10.295000 |    7.116000 | Destructor Invoked             | PeerConnectionImpl.cpp:341   | ~PeerConnectionImpl
[task 2021-08-17T00:59:31.853Z] 00:59:31     INFO - GECKO(9028) | [Child 2160: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:366: ~PeerConnectionImpl: PeerConnectionImpl destructor invoked for {40dcef0c-9301-41a9-836d-29c30aea36b5}
[task 2021-08-17T00:59:31.858Z] 00:59:31     INFO - GECKO(9028) | Timecard created 1629161959.993000
[task 2021-08-17T00:59:31.865Z] 00:59:31     INFO - GECKO(9028) |  Timestamp   | Delta       | Event                          | File                         | Function
[task 2021-08-17T00:59:31.872Z] 00:59:31     INFO - GECKO(9028) | ======================================================================================================================
[task 2021-08-17T00:59:31.879Z] 00:59:31     INFO - GECKO(9028) |     0.000000 |    0.000000 | Constructor Completed          | PeerConnectionImpl.cpp:332   | PeerConnectionImpl
[task 2021-08-17T00:59:31.886Z] 00:59:31     INFO - GECKO(9028) |     0.000000 |    0.000000 | Initializing PC Ctx            | PeerConnectionImpl.cpp:450   | Initialize
[task 2021-08-17T00:59:31.893Z] 00:59:31     INFO - GECKO(9028) |     0.136000 |    0.136000 | Set Remote Description         | PeerConnectionImpl.cpp:1381  | SetRemoteDescription
[task 2021-08-17T00:59:31.900Z] 00:59:31     INFO - GECKO(9028) |     0.268000 |    0.132000 | Create Answer                  | PeerConnectionImpl.cpp:1243  | CreateAnswer
[task 2021-08-17T00:59:31.907Z] 00:59:31     INFO - GECKO(9028) |     0.278000 |    0.010000 | Set Local Description          | PeerConnectionImpl.cpp:1281  | SetLocalDescription
[task 2021-08-17T00:59:31.914Z] 00:59:31     INFO - GECKO(9028) |     0.501000 |    0.223000 | Ice gathering state: gathering | PeerConnectionImpl.cpp:2537  | IceGatheringStateChange
[task 2021-08-17T00:59:31.921Z] 00:59:31     INFO - GECKO(9028) |     0.529000 |    0.028000 | Add Ice Candidate              | PeerConnectionImpl.cpp:1529  | AddIceCandidate
[task 2021-08-17T00:59:31.928Z] 00:59:31     INFO - GECKO(9028) |     0.590000 |    0.061000 | Add Ice Candidate              | PeerConnectionImpl.cpp:1529  | AddIceCandidate
[task 2021-08-17T00:59:31.934Z] 00:59:31     INFO - GECKO(9028) |     0.595000 |    0.005000 | Add Ice Candidate              | PeerConnectionImpl.cpp:1529  | AddIceCandidate
[task 2021-08-17T00:59:31.941Z] 00:59:31     INFO - GECKO(9028) |     0.841000 |    0.246000 | Ice gathering state: complete  | PeerConnectionImpl.cpp:2540  | IceGatheringStateChange
[task 2021-08-17T00:59:31.948Z] 00:59:31     INFO - GECKO(9028) |     0.926000 |    0.085000 | Ice state: checking            | PeerConnectionImpl.cpp:2481  | IceConnectionStateChange
[task 2021-08-17T00:59:31.955Z] 00:59:31     INFO - GECKO(9028) |     2.938000 |    2.012000 | Ice state: connected           | PeerConnectionImpl.cpp:2484  | IceConnectionStateChange
[task 2021-08-17T00:59:31.962Z] 00:59:31     INFO - GECKO(9028) |    10.290000 |    7.352000 | Destructor Invoked             | PeerConnectionImpl.cpp:341   | ~PeerConnectionImpl
[task 2021-08-17T00:59:31.971Z] 00:59:31     INFO - GECKO(9028) | [Child 2160: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:366: ~PeerConnectionImpl: PeerConnectionImpl destructor invoked for {fc0777fe-9d05-47d9-a28d-b426f81cf183}
[task 2021-08-17T00:59:31.978Z] 00:59:31     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel 1d761d44f50: Close()ing 1d761d6f660
[task 2021-08-17T00:59:31.984Z] 00:59:31     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel 1d761d44ea0: Close()ing 1d761d6f580
[task 2021-08-17T00:59:31.991Z] 00:59:31     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel 1d761d44d40: Close()ing 1d761d6f4a0
[task 2021-08-17T00:59:31.997Z] 00:59:31     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel 1d761d44be0: Close()ing 1d761d6f3c0
[task 2021-08-17T00:59:32.003Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel 1d761d44920: Close()ing 1d761d6f2e0
[task 2021-08-17T00:59:32.009Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel 1d761d44a80: Close()ing 1d761d6f200
[task 2021-08-17T00:59:32.015Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel 1d761d447c0: Close()ing 1d7614bac80
[task 2021-08-17T00:59:32.021Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel 1d761422a80: Close()ing 1d75940be40
[task 2021-08-17T00:59:32.028Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:331: PeerConnectionImpl: PeerConnectionImpl constructor for
[task 2021-08-17T00:59:32.035Z] 00:59:32     INFO - GECKO(9028) | [Parent 5480: Socket Thread]: D/mtransport NrIceCtx static call to find local stun addresses
[task 2021-08-17T00:59:32.043Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:331: PeerConnectionImpl: PeerConnectionImpl constructor for
[task 2021-08-17T00:59:32.049Z] 00:59:32     INFO - GECKO(9028) | [Parent 5480: Socket Thread]: D/mtransport NrIceCtx static call to find local stun addresses
[task 2021-08-17T00:59:32.055Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel Maximum message size (outgoing data): 2147483637 (set=no, enforced=yes)
[task 2021-08-17T00:59:32.061Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel Setting number of SCTP streams to 256, was 10/2048
[task 2021-08-17T00:59:32.069Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel DC Open: label channel_0/, type 0, inorder 1, prValue 0, listener 0, context 0, external: false, stream 65535
[task 2021-08-17T00:59:32.075Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Socket Thread]: D/DataChannel Registered 3 within the SCTP stack.
[task 2021-08-17T00:59:32.080Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel Inserting channel 65535 : 1d7614ba660
[task 2021-08-17T00:59:32.087Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel Queuing channel 1d7614ba660 (65535) to finish open
[task 2021-08-17T00:59:32.093Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel Init: origin = http://mochi.test:8888
[task 2021-08-17T00:59:32.100Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: I/signaling [main|PeerConnectionMedia] PeerConnectionMedia.cpp:75: OnStunAddrsAvailable: receiving (3) stun addrs
[task 2021-08-17T00:59:32.107Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: I/signaling [main|PeerConnectionMedia] PeerConnectionMedia.cpp:75: OnStunAddrsAvailable: receiving (3) stun addrs
[task 2021-08-17T00:59:32.114Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: E/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2778: GetStats: Found no pipelines matching selector.
[task 2021-08-17T00:59:32.122Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: E/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2778: GetStats: Found no pipelines matching selector.
[task 2021-08-17T00:59:32.128Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: I/signaling [main|sdp_config] sdp_config.c:86: SDP: Initialized config pointer: 1d75fa755f0
[task 2021-08-17T00:59:32.136Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: I/jsep [{c39427c5-6763-4414-a7a4-7e766d4e6c71} 1629161970666000 (id=6442450954 url=http://mochi.test:8888/tests/dom/media/webrtc/tests/]: stable -> have-local-offer
[task 2021-08-17T00:59:32.143Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: I/signaling [main|sdp_config] sdp_config.c:86: SDP: Initialized config pointer: 1d75fa75a50
[task 2021-08-17T00:59:32.151Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: I/jsep [{d355c6d2-2d52-4cbb-9426-8a332a5d5299} 1629161970717000 (id=6442450954 url=http://mochi.test:8888/tests/dom/media/webrtc/tests/]: stable -> have-remote-offer
[task 2021-08-17T00:59:32.157Z] 00:59:32     INFO - GECKO(9028) | (generic/EMERG) Exit UDP socket connected
[task 2021-08-17T00:59:32.164Z] 00:59:32     INFO - GECKO(9028) | (ice/WARNING) /builds/worker/checkouts/gecko/dom/media/webrtc/transport/third_p
[task 2021-08-17T00:59:32.171Z] 00:59:32     INFO - GECKO(9028) | arty/nICEr/src/net/nr_socket_multi_tcp.c:623 function nr_socket_multi_tcp_listen failed with error 3
[task 2021-08-17T00:59:32.176Z] 00:59:32     INFO - GECKO(9028) | (ice/WARNING) ICE(PC:{c39427c5-67
[task 2021-08-17T00:59:32.181Z] 00:59:32     INFO - GECKO(9028) | 63-4414-a7a4-7e766d4e6c71} 16291619
[task 2021-08-17T00:59:32.186Z] 00:59:32     INFO - GECKO(9028) | 70666000 (id=6442450954 u
[task 2021-08-17T00:59:32.191Z] 00:59:32     INFO - GECKO(9028) | rl=htt
[task 2021-08-17T00:59:32.197Z] 00:59:32     INFO - GECKO(9028) | p://mochi.test:8888/tests/dom/media/webrtc/t
[task 2021-08-17T00:59:32.202Z] 00:59:32     INFO - GECKO(9028) | e
[task 2021-08-17T00:59:32.208Z] 00:59:32     INFO - GECKO(9028) | sts/): failed to create passive TCP host candidate: 3
[task 2021-08-17T00:59:32.218Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Socket Thread]: D/mtransport NrIceCtx(PC:{c39427c5-6763-4414-a7a4-7e766d4e6c71} 1629161970666000 (id=6442450954 url=http://mochi.test:8888/tests/dom/media/webrtc/tests/): trickling candidate candidate:0 1 UDP 2122252543 2aaf0c3d-d28f-41c3-ae1d-b9edb3481911.local 56887 typ host
[task 2021-08-17T00:59:32.228Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Socket Thread]: D/mtransport Couldn't get default ICE candidate for 'PC:{c39427c5-6763-4414-a7a4-7e766d4e6c71} 1629161970666000 (id=6442450954 url=http://mochi.test:8888/tests/dom/media/webrtc/tests/ transport-id=transport_0', no candidates.
[task 2021-08-17T00:59:32.239Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Socket Thread]: D/mtransport NrIceCtx(PC:{c39427c5-6763-4414-a7a4-7e766d4e6c71} 1629161970666000 (id=6442450954 url=http://mochi.test:8888/tests/dom/media/webrtc/tests/): trickling candidate candidate:1 1 TCP 2105524479 2aaf0c3d-d28f-41c3-ae1d-b9edb3481911.local 9 typ host tcptype active
[task 2021-08-17T00:59:32.249Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Socket Thread]: D/mtransport Couldn't get default ICE candidate for 'PC:{c39427c5-6763-4414-a7a4-7e766d4e6c71} 1629161970666000 (id=6442450954 url=http://mochi.test:8888/tests/dom/media/webrtc/tests/ transport-id=transport_0', no candidates.
[task 2021-08-17T00:59:32.259Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Socket Thread]: D/mtransport Couldn't get default ICE candidate for 'PC:{c39427c5-6763-4414-a7a4-7e766d4e6c71} 1629161970666000 (id=6442450954 url=http://mochi.test:8888/tests/dom/media/webrtc/tests/ transport-id=transport_0', no candidates.
[task 2021-08-17T00:59:32.265Z] 00:59:32     INFO - GECKO(9028) | (ice/INFO) ICE(PC:{c39427c5-6763-4414-a7a4-7
[task 2021-08-17T00:59:32.272Z] 00:59:32     INFO - GECKO(9028) | e766d4e6c71} 1629161970666000 (id=6442450954 url=http://mochi.test:8888/tests/dom/media/webrtc/tests/): All candidates initialized
[task 2021-08-17T00:59:32.279Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: I/signaling [main|sdp_config] sdp_config.c:86: SDP: Initialized config pointer: 1d75fa75040
[task 2021-08-17T00:59:32.287Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: I/jsep [{d355c6d2-2d52-4cbb-9426-8a332a5d5299} 1629161970717000 (id=6442450954 url=http://mochi.test:8888/tests/dom/media/webrtc/tests/]: have-remote-offer -> stable
[task 2021-08-17T00:59:32.294Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel Maximum message size (outgoing data): 1073741823 (set=yes, enforced=no)
[task 2021-08-17T00:59:32.301Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel Setting number of SCTP streams to 256, was 10/2048
[task 2021-08-17T00:59:32.309Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel ConnectToTransport connecting DTLS transport with parameters: Transport ID: 'transport_0', Role: 'client', Local Port: '5000', Remote Port: '5000'
[task 2021-08-17T00:59:32.314Z] 00:59:32     INFO - GECKO(9028) | (generic/EMERG) Exit UDP socket connected
[task 2021-08-17T00:59:32.321Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel DataChannelConnection labeled  (1d761da1000) switching connection state CLOSED -> CONNECTING
[task 2021-08-17T00:59:32.328Z] 00:59:32     INFO - GECKO(9028) | (ice/WARNING) /builds/worker/checkouts/gecko/dom/media/webrtc/transport/third_party/nICEr/src/net/nr_socket_mult
[task 2021-08-17T00:59:32.332Z] 00:59:32     INFO - GECKO(9028) | i_t
[task 2021-08-17T00:59:32.338Z] 00:59:32     INFO - GECKO(9028) | cp.c:623 function nr_socket_multi_tcp_listen failed with error 3
[task 2021-08-17T00:59:32.343Z] 00:59:32     INFO - GECKO(9028) | (ice/WARNING) ICE(PC:{d355c6d2-2d52-4
[task 2021-08-17T00:59:32.349Z] 00:59:32     INFO - GECKO(9028) | cbb-9426-8a332a5d5299} 1629161970717000 (id=6442450954 url=h
[task 2021-08-17T00:59:32.355Z] 00:59:32     INFO - GECKO(9028) | ttp://mochi.test:8888/tests/dom/media/webrtc/tests/): failed to crea
[task 2021-08-17T00:59:32.362Z] 00:59:32     INFO - GECKO(9028) | te passive
[task 2021-08-17T00:59:32.367Z] 00:59:32     INFO - GECKO(9028) |  TCP host candidate: 3
[task 2021-08-17T00:59:32.375Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: I/signaling [main|sdp_config] sdp_config.c:86: SDP: Initialized config pointer: 1d7614922e0
[task 2021-08-17T00:59:32.394Z] 00:59:32     INFO - GECKO(9028) | (ice/WARNING) ICE(PC:{d355c6d2-2d52-4cbb-9426-8a332a5d5299} 1629161970717000 (id=6442450954 url=http://mochi.test:8888/tests/dom/media/webrtc/tests[Child 2160: Main Thread]: I/jsep [{c39427c5-6763-4414-a7a4-7e766d4e6c71} 1629161970666000 (id=6442450954 url=http://mochi.test:8888/tests/dom/media/webrtc/tests/]: have-local-offer -> stable
[task 2021-08-17T00:59:32.401Z] 00:59:32     INFO - GECKO(9028) | /): peer (PC:{d3[Child 2160: Main Thread]: D/DataChannel Maximum message size (outgoing data): 1073741823 (set=yes, enforced=no)
[task 2021-08-17T00:59:32.409Z] 00:59:32     INFO - GECKO(9028) | 55c6d2-2d52-4cbb-94[Child 2160: Main Thread]: D/DataChannel ConnectToTransport connecting DTLS transport with parameters: Transport ID: 'transport_0', Role: 'server', Local Port: '5000', Remote Port: '5000'
[task 2021-08-17T00:59:32.416Z] 00:59:32     INFO - GECKO(9028) | 26-8a3[Child 2160: Main Thread]: D/DataChannel DataChannelConnection labeled  (1d761431c00) switching connection state CLOSED -> CONNECTING
[task 2021-08-17T00:59:32.423Z] 00:59:32     INFO - GECKO(9028) | 32a5d[Child 2160: Main Thread]: D/DataChannel Removing channel 65535 : 1d7614ba660
[task 2021-08-17T00:59:32.429Z] 00:59:32     INFO - GECKO(9028) | 5299} 162916197[Child 2160: Main Thread]: D/DataChannel Inserting channel 1 : 1d7614ba660
[task 2021-08-17T00:59:32.439Z] 00:59:32     INFO - GECKO(9028) | 0717000 (id=6442450954 url=http://mochi.test:8888/tests/dom/media/webrtc/tests/:default) has no stream matching stream [Child 2160: Main Thread]: E/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2778: GetStats: Found no pipelines matching selector.
[task 2021-08-17T00:59:32.446Z] 00:59:32     INFO - GECKO(9028) | PC:{d355c6d2-2d5[Child 2160: Main Thread]: E/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2778: GetStats: Found no pipelines matching selector.
[task 2021-08-17T00:59:32.452Z] 00:59:32     INFO - GECKO(9028) | 2-4cbb-9426-8a332a5d5299} 1629161970717000 (
[task 2021-08-17T00:59:32.459Z] 00:59:32     INFO - GECKO(9028) | id=6442450954 url=http://mochi.test:8888/tests/dom/media/webrtc/te
[task 2021-08-17T00:59:32.468Z] 00:59:32     INFO - GECKO(9028) | sts/ transport-id=transport_0 - 590cc32f:e2ff58e57b32d
[task 2021-08-17T00:59:32.473Z] 00:59:32     INFO - GECKO(9028) | 8
[task 2021-08-17T00:59:32.477Z] 00:59:32     INFO - GECKO(9028) | 9c
[task 2021-08-17T00:59:32.483Z] 00:59:32     INFO - GECKO(9028) | ee0235ab75e7d021
[task 2021-08-17T00:59:32.494Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Socket Thread]: D/mtransport Setting up DTLS as client
[task 2021-08-17T00:59:32.513Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Socket Thread]: E/mtransport Couldn't disable 'PC:{d355c6d2-2d52-4cbb-9426-8a332a5d5299} 1629161970717000 (id=6442450954 url=http://mochi.test:8888/tests/dom/media/webrtc/tests/ transport-id=transport_0':2
[task 2021-08-17T00:59:32.522Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Socket Thread]: D/DataChannel Registered 4 within the SCTP stack.
[task 2021-08-17T00:59:32.539Z] 00:59:32     INFO - GECKO(9028) | [Child 2160: Socket Thread]: D/DataChannel Setting transport signals, dtls not open yet
[task 2021-08-17T00:59:32.557Z] 00:59:32     INFO - GECKO(9028) | (ic
[task 2021-08-17T00:59:32.562Z] 00:59:32     INFO - GECKO(9028) | e
[task 2021-08-17T00:59:32.589Z] 00:59:32     INFO - GECKO(9028) | /NOTICE) ICE(PC:{d35
[task 2021-08-17T00:59:32.600Z] 00:59:32     INFO - GECKO(9028) | 5c6d2-2d52-4cbb-9426-8a332a5d5299} 16
[task 2021-08-17T00:59:32.608Z] 00:59:32     INFO - GECKO(9028) | 291619
[task 2021-08-17T00:59:32.622Z] 00:59:32     INFO - GECKO(9028) | 70717000 (id=6442450954 url=http://m
[task 2021-08-17T00:59:32.627Z] 00:59:32     INFO - GECKO(9028) | o
<...>
[task 2021-08-17T01:00:05.743Z] 01:00:05     INFO - TEST-PASS | dom/media/webrtc/tests/mochitests/test_dataChannel_hostnameObfuscation.html | iceConnectionState should not be undefined 
[task 2021-08-17T01:00:05.749Z] 01:00:05     INFO - PeerConnectionWrapper (pcRemote): oniceconnectionstatechange fired, new state is: failed
[task 2021-08-17T01:00:05.754Z] 01:00:05     INFO - Buffered messages finished
[task 2021-08-17T01:00:05.769Z] 01:00:05     INFO - TEST-UNEXPECTED-FAIL | dom/media/webrtc/tests/mochitests/test_dataChannel_hostnameObfuscation.html | PeerConnectionWrapper (pcRemote): legal ICE state transition from new to failed 
[task 2021-08-17T01:00:05.770Z] 01:00:05     INFO -     SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
[task 2021-08-17T01:00:05.770Z] 01:00:05     INFO -     logIceConnectionState/this.ice_connection_callbacks.logIceStatus@dom/media/webrtc/tests/mochitests/pc.js:1551:13
[task 2021-08-17T01:00:05.771Z] 01:00:05     INFO -     PeerConnectionWrapper/this._pc.oniceconnectionstatechange/<@dom/media/webrtc/tests/mochitests/pc.js:914:42
[task 2021-08-17T01:00:05.772Z] 01:00:05     INFO -     PeerConnectionWrapper/this._pc.oniceconnectionstatechange@dom/media/webrtc/tests/mochitests/pc.js:913:48
[task 2021-08-17T01:00:05.777Z] 01:00:05     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel Closing all channels (connection 1d761da1000)
[task 2021-08-17T01:00:05.784Z] 01:00:05     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel DataChannelConnection labeled transport_0 (1d761da1000) switching connection state CONNECTING -> CLOSED
[task 2021-08-17T01:00:05.790Z] 01:00:05     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel Connection 1d761da1000: Sending outgoing stream reset for 0 streams
[task 2021-08-17T01:00:05.795Z] 01:00:05     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel No streams to reset
[task 2021-08-17T01:00:05.801Z] 01:00:05     INFO - GECKO(9028) | JavaScript error: http://mochi.test:8888/tests/dom/media/webrtc/tests/mochitests/pc.js, line 919: Error: ICE failed
[task 2021-08-17T01:00:05.808Z] 01:00:05     INFO - GECKO(9028) | [Child 2160: Main Thread]: E/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2778: GetStats: Found no pipelines matching selector.
<...>
[task 2021-08-17T01:02:31.025Z] 01:02:31     INFO - GECKO(9028) | [Child 2160: Main Thread]: E/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2778: GetStats: Found no pipelines matching selector.
[task 2021-08-17T01:02:31.064Z] 01:02:31     INFO - GECKO(9028) | JavaScript error: http://mochi.test:8888/tests/dom/media/webrtc/tests/mochitests/pc.js, line 135: Error: timeout after 180s: channel didn't open in time
[task 2021-08-17T01:02:32.016Z] 01:02:32     INFO - GECKO(9028) | [Child 2160: Main Thread]: E/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2778: GetStats: Found no pipelines matching selector.
<...>
[task 2021-08-17T01:04:48.025Z] 01:04:48     INFO - GECKO(9028) | [Child 2160: Main Thread]: E/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2778: GetStats: Found no pipelines matching selector.
[task 2021-08-17T01:04:48.518Z] 01:04:48     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-08-17T01:04:48.528Z] 01:04:48     INFO - TEST-UNEXPECTED-FAIL | dom/media/webrtc/tests/mochitests/test_dataChannel_hostnameObfuscation.html | Test timed out. - 
[task 2021-08-17T01:04:49.019Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: E/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2778: GetStats: Found no pipelines matching selector.
[task 2021-08-17T01:04:49.028Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: E/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2778: GetStats: Found no pipelines matching selector.
[task 2021-08-17T01:04:49.567Z] 01:04:49     INFO - GECKO(9028) | MEMORY STAT | vsize 6586MB | vsizeMaxContiguous 109854208MB | residentFast 57MB | heapAllocated 6MB
[task 2021-08-17T01:04:49.589Z] 01:04:49     INFO - TEST-OK | dom/media/webrtc/tests/mochitests/test_dataChannel_hostnameObfuscation.html | took 319370ms
[task 2021-08-17T01:04:49.608Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2109: CloseInt: Closing PeerConnectionImpl {c39427c5-6763-4414-a7a4-7e766d4e6c71}; ending call
[task 2021-08-17T01:04:49.618Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: I/jsep [{c39427c5-6763-4414-a7a4-7e766d4e6c71} 1629161970666000 (id=6442450954 url=http://mochi.test:8888/tests/dom/media/webrtc/tests/]: stable -> closed
[task 2021-08-17T01:04:49.628Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2115: CloseInt: Destroying DataChannelConnection 1d761431c00 for {c39427c5-6763-4414-a7a4-7e766d4e6c71}
[task 2021-08-17T01:04:49.636Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel Destroying DataChannelConnection 1d761431c00
[task 2021-08-17T01:04:49.644Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel Closing all channels (connection 1d761431c00)
[task 2021-08-17T01:04:49.653Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel DataChannelConnection labeled transport_0 (1d761431c00) switching connection state CONNECTING -> CLOSED
[task 2021-08-17T01:04:49.661Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel Connection 1d761431c00/Channel 1d7614ba660: Closing stream 1
[task 2021-08-17T01:04:49.668Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel Removing channel 1 : 1d7614ba660
[task 2021-08-17T01:04:49.676Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel Connection 1d761431c00: Resetting outgoing stream 1
[task 2021-08-17T01:04:49.685Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel DataChannelConnection labeled channel_0(1d7614ba660) (stream 1) changing ready state CONNECTING -> CLOSING
[task 2021-08-17T01:04:49.691Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel Destroying Data channel 1
[task 2021-08-17T01:04:49.698Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel closing pending channel 1d7614ba660, stream 1
[task 2021-08-17T01:04:49.705Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel Connection 1d761431c00/Channel 1d7614ba660: Closing stream 1
[task 2021-08-17T01:04:49.712Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel Removing channel 1 : 1d7614ba660
[task 2021-08-17T01:04:49.719Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel Channel already closing/closed (2)
[task 2021-08-17T01:04:49.726Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel Connection 1d761431c00: Sending outgoing stream reset for 1 streams
[task 2021-08-17T01:04:49.733Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: E/DataChannel ***failed: setsockopt RESET, errno 2
[task 2021-08-17T01:04:49.740Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel Clearing resets for 1 streams
[task 2021-08-17T01:04:49.747Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Socket Thread]: D/DataChannel Deregistered 3 from the SCTP stack.
[task 2021-08-17T01:04:49.755Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: E/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2778: GetStats: Found no pipelines matching selector.
[task 2021-08-17T01:04:49.765Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2109: CloseInt: Closing PeerConnectionImpl {d355c6d2-2d52-4cbb-9426-8a332a5d5299}; ending call
[task 2021-08-17T01:04:49.791Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: I/jsep [{d355c6d2-2d52-4cbb-9426-8a332a5d5299} 1629161970717000 (id=6442450954 url=http://mochi.test:8888/tests/dom/media/webrtc/tests/]: stable -> closed
[task 2021-08-17T01:04:49.819Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2115: CloseInt: Destroying DataChannelConnection 1d761da1000 for {d355c6d2-2d52-4cbb-9426-8a332a5d5299}
[task 2021-08-17T01:04:49.831Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel Destroying DataChannelConnection 1d761da1000
[task 2021-08-17T01:04:49.845Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel Closing all channels (connection 1d761da1000)
[task 2021-08-17T01:04:49.870Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel DataChannelConnection labeled transport_0 (1d761da1000) switching connection state CLOSED -> CLOSED
[task 2021-08-17T01:04:49.891Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel Connection 1d761da1000: Sending outgoing stream reset for 0 streams
[task 2021-08-17T01:04:49.903Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel No streams to reset
[task 2021-08-17T01:04:49.919Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Socket Thread]: D/DataChannel Deregistered 4 from the SCTP stack.
[task 2021-08-17T01:04:49.947Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel DataChannelConnection labeled channel_0(1d7614ba660) (stream 1) changing ready state CLOSING -> CLOSED
[task 2021-08-17T01:04:49.964Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel operator(): sending ON_CHANNEL_CLOSED for channel_0/: 1
[task 2021-08-17T01:04:49.985Z] 01:04:49     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel 1d761422c90(1d7614ba660): OnChannelClosed - Dispatching
[task 2021-08-17T01:04:50.003Z] 01:04:50     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel Deleting DataChannelConnection 1d761431c00
[task 2021-08-17T01:04:50.021Z] 01:04:50     INFO - GECKO(9028) | [Child 2160: Main Thread]: D/DataChannel Deleting DataChannelConnection 1d761da1000
[task 2021-08-17T01:04:50.065Z] 01:04:50     INFO - TEST-START | dom/media/webrtc/tests/mochitests/test_dataChannel_noOffer.html

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-beta: 2

Platform and build breakdown:

• windows10-aarch64-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1726084&startday=2021-08-16&endday=2021-08-22&tree=all

Comment 2

[Intermittent Failures Robot]

1 failures in 2580 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-release: 1

Platform and build breakdown:

• windows10-aarch64-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1726084&startday=2021-08-23&endday=2021-08-29&tree=all

Comment 3

[Intermittent Failures Robot]

1 failures in 3266 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• windows10-aarch64-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1726084&startday=2021-09-06&endday=2021-09-12&tree=all

Comment 4

[Intermittent Failures Robot]

1 failures in 3376 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 1

Platform and build breakdown:

• windows10-aarch64-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1726084&startday=2021-09-27&endday=2021-10-03&tree=all

Comment 5

[Intermittent Failures Robot]

1 failures in 3626 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• windows10-aarch64-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1726084&startday=2021-10-04&endday=2021-10-10&tree=all

Comment 6

[BugBot [:suhaib / :marco/ :calixte]]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Comment 7

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=364530874&repo=mozilla-beta

Comment 8

[Intermittent Failures Robot]

1 failures in 3444 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 1

Platform and build breakdown:

• windows10-aarch64-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1726084&startday=2022-01-17&endday=2022-01-23&tree=all

Comment 9

[BugBot [:suhaib / :marco/ :calixte]]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Comment 10

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=368972420&repo=mozilla-central

Comment 11

[Intermittent Failures Robot]

1 failures in 2992 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• windows10-aarch64-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1726084&startday=2022-02-21&endday=2022-02-27&tree=all

Comment 12

[BugBot [:suhaib / :marco/ :calixte]]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.