Closed Bug 1719926 Opened 5 years ago Closed 4 years ago

Intermittent [tier 2] dom/media/webrtc/tests/mochitests/test_peerConnection_restartIceNoBundleNoRtcpMux.html | Error in test execution: Error: ICE failed PeerConnectionWrapper/this._pc.oniceconnectionstatechange@https://example.com/*/mochitests/pc.js:919:

Categories

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

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

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


[task 2021-07-09T13:18:08.273Z] 13:18:08     INFO - TEST-START | dom/media/webrtc/tests/mochitests/test_peerConnection_restartIceNoBundleNoRtcpMux.html
[task 2021-07-09T13:18:08.280Z] 13:18:08     INFO - GECKO(10580) | TEST DEVICES: No test device found in media.audio_loopback_dev, using fake audio streams.
[task 2021-07-09T13:18:08.287Z] 13:18:08     INFO - GECKO(10580) | TEST DEVICES: No test device found in media.video_loopback_dev, using fake video streams.
[task 2021-07-09T13:18:08.307Z] 13:18:08     INFO - GECKO(10580) | Timecard created 1625836668.836000
[task 2021-07-09T13:18:08.358Z] 13:18:08     INFO - GECKO(10580) |  Timestamp   | Delta       | Event                          | File                         | Function
[task 2021-07-09T13:18:08.414Z] 13:18:08     INFO - GECKO(10580) | ======================================================================================================================
[task 2021-07-09T13:18:08.469Z] 13:18:08     INFO - GECKO(10580) |     0.053000 |    0.053000 | Constructor Completed          | PeerConnectionImpl.cpp:332   | PeerConnectionImpl
[task 2021-07-09T13:18:08.523Z] 13:18:08     INFO - GECKO(10580) |     0.054000 |    0.001000 | Initializing PC Ctx            | PeerConnectionImpl.cpp:450   | Initialize
[task 2021-07-09T13:18:08.581Z] 13:18:08     INFO - GECKO(10580) |     0.845000 |    0.791000 | Create Offer                   | PeerConnectionImpl.cpp:1212  | CreateOffer
[task 2021-07-09T13:18:08.636Z] 13:18:08     INFO - GECKO(10580) |     0.884000 |    0.039000 | Set Local Description          | PeerConnectionImpl.cpp:1281  | SetLocalDescription
[task 2021-07-09T13:18:08.692Z] 13:18:08     INFO - GECKO(10580) |     1.637000 |    0.753000 | Ice gathering state: gathering | PeerConnectionImpl.cpp:2537  | IceGatheringStateChange
[task 2021-07-09T13:18:08.750Z] 13:18:08     INFO - GECKO(10580) |     1.878000 |    0.241000 | Ice gathering state: complete  | PeerConnectionImpl.cpp:2540  | IceGatheringStateChange
[task 2021-07-09T13:18:08.806Z] 13:18:08     INFO - GECKO(10580) |     2.054000 |    0.176000 | Set Remote Description         | PeerConnectionImpl.cpp:1381  | SetRemoteDescription
[task 2021-07-09T13:18:08.860Z] 13:18:08     INFO - GECKO(10580) |     3.330000 |    1.276000 | Add Ice Candidate              | PeerConnectionImpl.cpp:1529  | AddIceCandidate
[task 2021-07-09T13:18:08.914Z] 13:18:08     INFO - GECKO(10580) |     4.057000 |    0.727000 | Add Ice Candidate              | PeerConnectionImpl.cpp:1529  | AddIceCandidate
[task 2021-07-09T13:18:08.966Z] 13:18:08     INFO - GECKO(10580) |     4.191000 |    0.134000 | Add Ice Candidate              | PeerConnectionImpl.cpp:1529  | AddIceCandidate
[task 2021-07-09T13:18:09.038Z] 13:18:09     INFO - GECKO(10580) |     4.740000 |    0.549000 | Ice state: checking            | PeerConnectionImpl.cpp:2481  | IceConnectionStateChange
[task 2021-07-09T13:18:09.080Z] 13:18:09     INFO - GECKO(10580) |     9.414000 |    4.674000 | Ice state: connected           | PeerConnectionImpl.cpp:2484  | IceConnectionStateChange
[task 2021-07-09T13:18:09.138Z] 13:18:09     INFO - GECKO(10580) |    12.641000 |    3.227000 | Create Offer                   | PeerConnectionImpl.cpp:1212  | CreateOffer
[task 2021-07-09T13:18:09.180Z] 13:18:09     INFO - GECKO(10580) |    12.688000 |    0.047000 | Set Local Description          | PeerConnectionImpl.cpp:1281  | SetLocalDescription
[task 2021-07-09T13:18:09.223Z] 13:18:09     INFO - GECKO(10580) |    12.820000 |    0.132000 | Ice gathering state: gathering | PeerConnectionImpl.cpp:2537  | IceGatheringStateChange
[task 2021-07-09T13:18:09.260Z] 13:18:09     INFO - GECKO(10580) |    14.039000 |    1.219000 | Ice gathering state: complete  | PeerConnectionImpl.cpp:2540  | IceGatheringStateChange
[task 2021-07-09T13:18:09.291Z] 13:18:09     INFO - GECKO(10580) |    14.143000 |    0.104000 | Set Local Description          | PeerConnectionImpl.cpp:1281  | SetLocalDescription
[task 2021-07-09T13:18:09.321Z] 13:18:09     INFO - GECKO(10580) |    14.305000 |    0.162000 | Create Offer                   | PeerConnectionImpl.cpp:1212  | CreateOffer
[task 2021-07-09T13:18:09.349Z] 13:18:09     INFO - GECKO(10580) |    14.416000 |    0.111000 | Set Local Description          | PeerConnectionImpl.cpp:1281  | SetLocalDescription
[task 2021-07-09T13:18:09.374Z] 13:18:09     INFO - GECKO(10580) |    15.484000 |    1.068000 | Set Remote Description         | PeerConnectionImpl.cpp:1381  | SetRemoteDescription
[task 2021-07-09T13:18:09.395Z] 13:18:09     INFO - GECKO(10580) |    19.459000 |    3.975000 | Destructor Invoked             | PeerConnectionImpl.cpp:341   | ~PeerConnectionImpl
[task 2021-07-09T13:18:09.430Z] 13:18:09     INFO - GECKO(10580) | [Child 13476: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:366: ~PeerConnectionImpl: PeerConnectionImpl destructor invoked for {1c536410-5e60-4340-9004-c10c7daf092e}
<...>
[task 2021-07-09T13:22:25.357Z] 13:22:25     INFO - TEST-PASS | dom/media/webrtc/tests/mochitests/test_peerConnection_restartIceNoBundleNoRtcpMux.html | PeerConnectionWrapper (pcLocal): legal ICE state transition from checking to failed 
[task 2021-07-09T13:22:25.362Z] 13:22:25     INFO - Buffered messages finished
[task 2021-07-09T13:22:25.376Z] 13:22:25     INFO - TEST-UNEXPECTED-FAIL | dom/media/webrtc/tests/mochitests/test_peerConnection_restartIceNoBundleNoRtcpMux.html | Error in test execution: Error: ICE failed PeerConnectionWrapper/this._pc.oniceconnectionstatechange@https://example.com/tests/dom/media/webrtc/tests/mochitests/pc.js:919:31 ...  
[task 2021-07-09T13:22:25.377Z] 13:22:25     INFO - SimpleTest.ok@https://example.com/tests/SimpleTest/SimpleTest.js:417:16
[task 2021-07-09T13:22:25.377Z] 13:22:25     INFO - execute/<@https://example.com/tests/dom/media/webrtc/tests/mochitests/head.js:1007:11
[task 2021-07-09T13:22:25.385Z] 13:22:25     INFO - GECKO(10580) | [Child 13476: Socket Thread]: E/mtransport /builds/worker/checkouts/gecko/dom/media/webrtc/transport/transportlayerice.cpp:161: Flow[transport_0(none)]; Layer[ice]: state 3->5
[task 2021-07-09T13:22:25.394Z] 13:22:25     INFO - TEST-FAIL | dom/media/webrtc/tests/mochitests/test_peerConnection_restartIceNoBundleNoRtcpMux.html | The author of the test has indicated that flaky timeouts are expected.  Reason: WebRTC inherently depends on timeouts 
[task 2021-07-09T13:22:25.401Z] 13:22:25     INFO - GECKO(10580) | [Child 13476: Socket Thread]: E/mtransport Flow[transport_0(none)]; Layer[dtls]: Lower layer experienced an error
[task 2021-07-09T13:22:25.406Z] 13:22:25     INFO - Closing peer connections
[task 2021-07-09T13:22:25.415Z] 13:22:25     INFO - GECKO(10580) | [Child 13476: Socket Thread]: E/mtransport /builds/worker/checkouts/gecko/dom/media/webrtc/transport/transportlayerdtls.cpp:872: Flow[transport_0(none)]; Layer[dtls]: state 3->5
[task 2021-07-09T13:22:25.421Z] 13:22:25     INFO - Waiting for track {30e16c71-4f58-4042-843c-d073ac6ccca9} (audio) to end.
[task 2021-07-09T13:22:25.430Z] 13:22:25     INFO - TEST-FAIL | dom/media/webrtc/tests/mochitests/test_peerConnection_restartIceNoBundleNoRtcpMux.html | The author of the test has indicated that flaky timeouts are expected.  Reason: WebRTC inherently depends on timeouts 
[task 2021-07-09T13:22:25.438Z] 13:22:25     INFO - GECKO(10580) | [Child 13476: Socket Thread]: E/mtransport /builds/worker/checkouts/gecko/dom/media/webrtc/transport/transportlayersrtp.cpp:175: Flow[transport_0(none)]; Layer[srtp]: state 3->5
[task 2021-07-09T13:22:25.444Z] 13:22:25     INFO - GECKO(10580) | (ice/INFO) ICE-PEER(PC:{e9d19b53-9be9
[task 2021-07-09T13:22:25.451Z] 13:22:25     INFO - Waiting for track {19d605b0-ce0e-43a7-954c-976e62827c1d} (video) to end.
[task 2021-07-09T13:22:25.456Z] 13:22:25     INFO - GECKO(10580) | -4324-abf2-8
[task 2021-07-09T13:22:25.466Z] 13:22:25     INFO - TEST-FAIL | dom/media/webrtc/tests/mochitests/test_peerConnection_restartIceNoBundleNoRtcpMux.html | The author of the test has indicated that flaky timeouts are expected.  Reason: WebRTC inherently depends on timeouts 
[task 2021-07-09T13:22:25.471Z] 13:22:25     INFO - GECKO(10580) | 8
<...>
[task 2021-07-09T13:22:25.698Z] 13:22:25     INFO - GECKO(10580) | ample.com/tests/dom/media/[Child 13476: WebRTCPD #1]: E/signaling [WebRTCPD #1|WebrtcAudioSessionConduit] AudioConduit.cpp:629: SendAudioFrame Engine not transmitting
[task 2021-07-09T13:22:25.705Z] 13:22:25     INFO - GECKO(10580) | [Child 13476: WebRTCPD #3]: E/signaling [WebRTCPD #3|WebrtcAudioSessionConduit] AudioConduit.cpp:629: SendAudioFrame Engine not transmitting
[task 2021-07-09T13:22:25.714Z] 13:22:25     INFO - TEST-FAIL | dom/media/webrtc/tests/mochitests/test_peerConnection_restartIceNoBundleNoRtcpMux.html | The author of the test has indicated that flaky timeouts are expected.  Reason: WebRTC inherently depends on timeouts 
[task 2021-07-09T13:22:25.719Z] 13:22:25     INFO - GECKO(10580) | w
[task 2021-07-09T13:22:25.726Z] 13:22:25     INFO - GECKO(10580) | ebrtc/tests/moc)[Child 13476: WebRTCPD #3]: E/signaling [WebRTCPD #3|WebrtcAudioSessionConduit] AudioConduit.cpp:629: SendAudioFrame Engine not transmitting
[task 2021-07-09T13:22:25.733Z] 13:22:25     INFO - GECKO(10580) | [Child 13476: WebRTCPD #4]: E/signaling [WebRTCPD #4|WebrtcAudioSessionConduit] AudioConduit.cpp:629: SendAudioFrame Engine not transmitting
[task 2021-07-09T13:22:25.740Z] 13:22:25     INFO - GECKO(10580) | /ST[Child 13476: WebRTCPD #4]: E/signaling [WebRTCPD #4|WebrtcAudioSessionConduit] AudioConduit.cpp:629: SendAudioFrame Engine not transmitting
[task 2021-07-09T13:22:25.748Z] 13:22:25     INFO - GECKO(10580) | REA[Child 13476: WebRTCPD #3]: E/signaling [WebRTCPD #3|WebrtcAudioSessionConduit] AudioConduit.cpp:629: SendAudioFrame Engine not transmitting
[task 2021-07-09T13:22:25.756Z] 13:22:25     INFO - TEST-PASS | dom/media/webrtc/tests/mochitests/test_peerConnection_restartIceNoBundleNoRtcpMux.html | Event target should be the correct track 
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.