Intermittent TEST-UNEXPECTED-TIMEOUT | /webrtc/RTCPeerConnection-onsignalingstatechanged.https.html | Executor hit external timeout (this may indicate a hang)
Categories
(Core :: WebRTC, defect, P5)
Tracking
()
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure)
Filed by: rmaries [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=288604235&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Uw1Or65vSgaiwZywECrcfQ/runs/0/artifacts/public/logs/live_backing.log
[task 2020-02-12T22:54:57.860Z] 22:54:57 INFO - TEST-START | /webrtc/RTCPeerConnection-onsignalingstatechanged.https.html
[task 2020-02-12T22:55:25.082Z] 22:55:25 INFO - PID 9068 | [CodeCoverage] Requested flush for 9280.
[task 2020-02-12T22:55:28.594Z] 22:55:28 INFO - TEST-UNEXPECTED-TIMEOUT | /webrtc/RTCPeerConnection-onsignalingstatechanged.https.html | Executor hit external timeout (this may indicate a hang)
[task 2020-02-12T22:55:28.594Z] 22:55:28 INFO - File "c:\mozilla-build\python\Lib\threading.py", line 774, in __bootstrap
[task 2020-02-12T22:55:28.594Z] 22:55:28 INFO - self.__bootstrap_inner()
[task 2020-02-12T22:55:28.594Z] 22:55:28 INFO - File "c:\mozilla-build\python\Lib\threading.py", line 801, in __bootstrap_inner
[task 2020-02-12T22:55:28.594Z] 22:55:28 INFO - self.run()
[task 2020-02-12T22:55:28.594Z] 22:55:28 INFO - File "c:\mozilla-build\python\Lib\threading.py", line 754, in run
[task 2020-02-12T22:55:28.594Z] 22:55:28 INFO - self.__target(*self.__args, **self.__kwargs)
[task 2020-02-12T22:55:28.594Z] 22:55:28 INFO - File "Z:\task_1581545235\build\tests\web-platform\tests\tools\wptrunner\wptrunner\executors\executormarionette.py", line 642, in run_func
[task 2020-02-12T22:55:28.594Z] 22:55:28 INFO - self.result = True, self.func(self.protocol, self.url, self.timeout)
[task 2020-02-12T22:55:28.594Z] 22:55:28 INFO - File "Z:\task_1581545235\build\tests\web-platform\tests\tools\wptrunner\wptrunner\executors\executormarionette.py", line 762, in do_testharness
[task 2020-02-12T22:55:28.594Z] 22:55:28 INFO - self.protocol.coverage.dump()
[task 2020-02-12T22:55:28.594Z] 22:55:28 INFO - File "Z:\task_1581545235\build\tests\web-platform\tests\tools\wptrunner\wptrunner\executors\executormarionette.py", line 484, in dump
[task 2020-02-12T22:55:28.594Z] 22:55:28 INFO - error = self.marionette.execute_async_script(script)
[task 2020-02-12T22:55:28.594Z] 22:55:28 INFO - File "Z:\task_1581545235\build\venv\lib\site-packages\marionette_driver\marionette.py", line 1656, in execute_async_script
[task 2020-02-12T22:55:28.594Z] 22:55:28 INFO - rv = self._send_message("WebDriver:ExecuteAsyncScript", body, key="value")
[task 2020-02-12T22:55:28.594Z] 22:55:28 INFO - File "Z:\task_1581545235\build\venv\lib\site-packages\marionette_driver\decorators.py", line 26, in _
[task 2020-02-12T22:55:28.594Z] 22:55:28 INFO - return func(*args, **kwargs)
[task 2020-02-12T22:55:28.595Z] 22:55:28 INFO - File "Z:\task_1581545235\build\venv\lib\site-packages\marionette_driver\marionette.py", line 590, in _send_message
[task 2020-02-12T22:55:28.595Z] 22:55:28 INFO - msg = self.client.request(name, params)
[task 2020-02-12T22:55:28.595Z] 22:55:28 INFO - File "Z:\task_1581545235\build\venv\lib\site-packages\marionette_driver\transport.py", line 273, in request
[task 2020-02-12T22:55:28.595Z] 22:55:28 INFO - return self.receive()
[task 2020-02-12T22:55:28.595Z] 22:55:28 INFO - File "Z:\task_1581545235\build\venv\lib\site-packages\marionette_driver\transport.py", line 153, in receive
[task 2020-02-12T22:55:28.595Z] 22:55:28 INFO - chunk = self._sock.recv(bytes_to_recv)
[task 2020-02-12T22:55:28.595Z] 22:55:28 INFO - TEST-INFO took 30735ms
[task 2020-02-12T22:55:28.595Z] 22:55:28 INFO - No more tests
[task 2020-02-12T22:55:32.674Z] 22:55:32 INFO - PID 9068 | [CodeCoverage] flush completed.
[task 2020-02-12T22:55:32.712Z] 22:55:32 INFO - PID 9068 | [CodeCoverage] JS flush completed.
[task 2020-02-12T22:55:40.125Z] 22:55:40 INFO - PID 9068 | [CodeCoverage] flush completed.
[task 2020-02-12T22:55:40.154Z] 22:55:40 INFO - PID 9068 | [CodeCoverage] JS flush completed.
[task 2020-02-12T22:55:46.836Z] 22:55:46 INFO - PID 9068 | [CodeCoverage] flush completed.
[task 2020-02-12T22:55:46.881Z] 22:55:46 INFO - PID 9068 | [CodeCoverage] JS flush completed.
[task 2020-02-12T22:55:54.193Z] 22:55:54 INFO - PID 9068 | [CodeCoverage] flush completed.
[task 2020-02-12T22:55:54.193Z] 22:55:54 INFO - PID 9068 | [CodeCoverage] JS flush completed.
[task 2020-02-12T22:56:13.448Z] 22:56:13 INFO - PID 9068 | Timecard created 1581548122.207000
[task 2020-02-12T22:56:13.448Z] 22:56:13 INFO - PID 9068 | Timestamp | Delta | Event | File | Function
[task 2020-02-12T22:56:13.450Z] 22:56:13 INFO - PID 9068 | =====================================================================================================================
[task 2020-02-12T22:56:13.450Z] 22:56:13 INFO - PID 9068 | 0.000000 | 0.000000 | Constructor Completed | PeerConnectionImpl.cpp:330 | PeerConnectionImpl
[task 2020-02-12T22:56:13.452Z] 22:56:13 INFO - PID 9068 | 0.002000 | 0.002000 | Initializing PC Ctx | PeerConnectionImpl.cpp:456 | Initialize
[task 2020-02-12T22:56:13.453Z] 22:56:13 INFO - PID 9068 | 0.029000 | 0.027000 | Create Offer | PeerConnectionImpl.cpp:1252 | CreateOffer
[task 2020-02-12T22:56:13.453Z] 22:56:13 INFO - PID 9068 | 0.050000 | 0.021000 | Set Local Description | PeerConnectionImpl.cpp:1321 | SetLocalDescription
[task 2020-02-12T22:56:13.453Z] 22:56:13 INFO - PID 9068 | 0.082000 | 0.032000 | Ice gathering state: gathering | PeerConnectionImpl.cpp:2588 | IceGatheringStateChange
[task 2020-02-12T22:56:13.454Z] 22:56:13 INFO - PID 9068 | 0.091000 | 0.009000 | Ice gathering state: complete | PeerConnectionImpl.cpp:2591 | IceGatheringStateChange
[task 2020-02-12T22:56:13.454Z] 22:56:13 INFO - PID 9068 | 51.238000 | 51.147000 | Destructor Invoked | PeerConnectionImpl.cpp:339 | ~PeerConnectionImpl
[task 2020-02-12T22:56:13.454Z] 22:56:13 INFO - PID 9068 | [Child 868: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:364: ~PeerConnectionImpl: PeerConnectionImpl destructor invoked for 0a0581cf8ca50d81
[task 2020-02-12T22:56:13.455Z] 22:56:13 INFO - PID 9068 | Timecard created 1581548122.213000
[task 2020-02-12T22:56:13.455Z] 22:56:13 INFO - PID 9068 | Timestamp | Delta | Event | File | Function
[task 2020-02-12T22:56:13.456Z] 22:56:13 INFO - PID 9068 | ==========================================================================================================
[task 2020-02-12T22:56:13.457Z] 22:56:13 INFO - PID 9068 | 0.000000 | 0.000000 | Constructor Completed | PeerConnectionImpl.cpp:330 | PeerConnectionImpl
[task 2020-02-12T22:56:13.457Z] 22:56:13 INFO - PID 9068 | 0.001000 | 0.001000 | Initializing PC Ctx | PeerConnectionImpl.cpp:456 | Initialize
[task 2020-02-12T22:56:13.457Z] 22:56:13 INFO - PID 9068 | 0.057000 | 0.056000 | Set Remote Description | PeerConnectionImpl.cpp:1408 | SetRemoteDescription
[task 2020-02-12T22:56:13.457Z] 22:56:13 INFO - PID 9068 | 0.075000 | 0.018000 | Create Answer | PeerConnectionImpl.cpp:1283 | CreateAnswer
[task 2020-02-12T22:56:13.458Z] 22:56:13 INFO - PID 9068 | 0.080000 | 0.005000 | Set Local Description | PeerConnectionImpl.cpp:1321 | SetLocalDescription
[task 2020-02-12T22:56:13.458Z] 22:56:13 INFO - PID 9068 | 51.234000 | 51.154000 | Destructor Invoked | PeerConnectionImpl.cpp:339 | ~PeerConnectionImpl
[task 2020-02-12T22:56:13.458Z] 22:56:13 INFO - PID 9068 | [Child 868: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:364: ~PeerConnectionImpl: PeerConnectionImpl destructor invoked for 38727df68e896b3c
[task 2020-02-12T22:56:13.458Z] 22:56:13 INFO - PID 9068 | Timecard created 1581548122.306000
[task 2020-02-12T22:56:13.459Z] 22:56:13 INFO - PID 9068 | Timestamp | Delta | Event | File | Function
[task 2020-02-12T22:56:13.459Z] 22:56:13 INFO - PID 9068 | ======================================================================================================================
[task 2020-02-12T22:56:13.460Z] 22:56:13 INFO - PID 9068 | 0.001000 | 0.001000 | Constructor Completed | PeerConnectionImpl.cpp:330 | PeerConnectionImpl
[task 2020-02-12T22:56:13.460Z] 22:56:13 INFO - PID 9068 | 0.001000 | 0.000000 | Initializing PC Ctx | PeerConnectionImpl.cpp:456 | Initialize
[task 2020-02-12T22:56:13.461Z] 22:56:13 INFO - PID 9068 | 0.020000 | 0.019000 | Create Offer | PeerConnectionImpl.cpp:1252 | CreateOffer
[task 2020-02-12T22:56:13.461Z] 22:56:13 INFO - PID 9068 | 0.031000 | 0.011000 | Set Local Description | PeerConnectionImpl.cpp:1321 | SetLocalDescription
[task 2020-02-12T22:56:13.462Z] 22:56:13 INFO - PID 9068 | 0.037000 | 0.006000 | Set Remote Description | PeerConnectionImpl.cpp:1408 | SetRemoteDescription
[task 2020-02-12T22:56:13.462Z] 22:56:13 INFO - PID 9068 | 0.040000 | 0.003000 | Ice gathering state: gathering | PeerConnectionImpl.cpp:2588 | IceGatheringStateChange
[task 2020-02-12T22:56:13.463Z] 22:56:13 INFO - PID 9068 | 0.061000 | 0.021000 | Ice gathering state: complete | PeerConnectionImpl.cpp:2591 | IceGatheringStateChange
[task 2020-02-12T22:56:13.463Z] 22:56:13 INFO - PID 9068 | 0.096000 | 0.035000 | Add Ice Candidate | PeerConnectionImpl.cpp:1541 | AddIceCandidate
[task 2020-02-12T22:56:13.463Z] 22:56:13 INFO - PID 9068 | 0.113000 | 0.017000 | Add Ice Candidate | PeerConnectionImpl.cpp:1541 | AddIceCandidate
[task 2020-02-12T22:56:13.464Z] 22:56:13 INFO - PID 9068 | 0.114000 | 0.001000 | Add Ice Candidate | PeerConnectionImpl.cpp:1541 | AddIceCandidate
[task 2020-02-12T22:56:13.464Z] 22:56:13 INFO - PID 9068 | 0.135000 | 0.021000 | Ice state: checking | PeerConnectionImpl.cpp:2488 | IceConnectionStateChange
[task 2020-02-12T22:56:13.464Z] 22:56:13 INFO - PID 9068 | 0.184000 | 0.049000 | Ice state: connected | PeerConnectionImpl.cpp:2491 | IceConnectionStateChange
[task 2020-02-12T22:56:13.464Z] 22:56:13 INFO - PID 9068 | 51.148000 | 50.964000 | Destructor Invoked | PeerConnectionImpl.cpp:339 | ~PeerConnectionImpl
[task 2020-02-12T22:56:13.469Z] 22:56:13 INFO - PID 9068 | [Child 868: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:364: ~PeerConnectionImpl: PeerConnectionImpl destructor invoked for 3f1dc2b0c38340d6
[task 2020-02-12T22:56:13.470Z] 22:56:13 INFO - PID 9068 | Timecard created 1581548122.309000
[task 2020-02-12T22:56:13.470Z] 22:56:13 INFO - PID 9068 | Timestamp | Delta | Event | File | Function
[task 2020-02-12T22:56:13.470Z] 22:56:13 INFO - PID 9068 | ======================================================================================================================
[task 2020-02-12T22:56:13.471Z] 22:56:13 INFO - PID 9068 | 0.000000 | 0.000000 | Constructor Completed | PeerConnectionImpl.cpp:330 | PeerConnectionImpl
[task 2020-02-12T22:56:13.471Z] 22:56:13 INFO - PID 9068 | 0.002000 | 0.002000 | Initializing PC Ctx | PeerConnectionImpl.cpp:456 | Initialize
[task 2020-02-12T22:56:13.472Z] 22:56:13 INFO - PID 9068 | 0.020000 | 0.018000 | Set Remote Description | PeerConnectionImpl.cpp:1408 | SetRemoteDescription
[task 2020-02-12T22:56:13.472Z] 22:56:13 INFO - PID 9068 | 0.032000 | 0.012000 | Create Answer | PeerConnectionImpl.cpp:1283 | CreateAnswer
[task 2020-02-12T22:56:13.473Z] 22:56:13 INFO - PID 9068 | 0.041000 | 0.009000 | Set Local Description | PeerConnectionImpl.cpp:1321 | SetLocalDescription
[task 2020-02-12T22:56:13.473Z] 22:56:13 INFO - PID 9068 | 0.046000 | 0.005000 | Add Ice Candidate | PeerConnectionImpl.cpp:1541 | AddIceCandidate
[task 2020-02-12T22:56:13.473Z] 22:56:13 INFO - PID 9068 | 0.049000 | 0.003000 | Add Ice Candidate | PeerConnectionImpl.cpp:1541 | AddIceCandidate
[task 2020-02-12T22:56:13.473Z] 22:56:13 INFO - PID 9068 | 0.054000 | 0.005000 | Add Ice Candidate | PeerConnectionImpl.cpp:1541 | AddIceCandidate
[task 2020-02-12T22:56:13.473Z] 22:56:13 INFO - PID 9068 | 0.059000 | 0.005000 | Add Ice Candidate | PeerConnectionImpl.cpp:1541 | AddIceCandidate
[task 2020-02-12T22:56:13.473Z] 22:56:13 INFO - PID 9068 | 0.059000 | 0.000000 | Add Ice Candidate | PeerConnectionImpl.cpp:1541 | AddIceCandidate
[task 2020-02-12T22:56:13.473Z] 22:56:13 INFO - PID 9068 | 0.062000 | 0.003000 | Ice gathering state: gathering | PeerConnectionImpl.cpp:2588 | IceGatheringStateChange
[task 2020-02-12T22:56:13.474Z] 22:56:13 INFO - PID 9068 | 0.084000 | 0.022000 | Ice state: checking | PeerConnectionImpl.cpp:2488 | IceConnectionStateChange
[task 2020-02-12T22:56:13.474Z] 22:56:13 INFO - PID 9068 | 0.112000 | 0.028000 | Ice gathering state: complete | PeerConnectionImpl.cpp:2591 | IceGatheringStateChange
[task 2020-02-12T22:56:13.474Z] 22:56:13 INFO - PID 9068 | 0.180000 | 0.068000 | Ice state: connected | PeerConnectionImpl.cpp:2491 | IceConnectionStateChange
[task 2020-02-12T22:56:13.474Z] 22:56:13 INFO - PID 9068 | 51.151000 | 50.971000 | Destructor Invoked | PeerConnectionImpl.cpp:339 | ~PeerConnectionImpl
[task 2020-02-12T22:56:13.474Z] 22:56:13 INFO - PID 9068 | [Child 868: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:364: ~PeerConnectionImpl: PeerConnectionImpl destructor invoked for e9c380bab669d21e
[task 2020-02-12T22:56:39.725Z] 22:56:39 INFO - Browser exited with return code 572
[task 2020-02-12T22:56:39.725Z] 22:56:39 INFO - PROCESS LEAKS None
[task 2020-02-12T22:56:39.725Z] 22:56:39 INFO - PROCESS LEAKS None
[task 2020-02-12T22:56:39.726Z] 22:56:39 INFO - Closing logging queue
[task 2020-02-12T22:56:39.726Z] 22:56:39 INFO - queue closed
[task 2020-02-12T22:56:39.726Z] 22:56:39 INFO - PROCESS LEAKS None
[task 2020-02-12T22:56:39.726Z] 22:56:39 INFO - Got 1 unexpected results
[task 2020-02-12T22:56:39.726Z] 22:56:39 INFO - SUITE-END | took 112s
[task 2020-02-12T22:56:39.759Z] 22:56:39 INFO - Removed font: Ahem.ttf
[task 2020-02-12T22:56:39.778Z] 22:56:39 INFO - Closing logging queue
[task 2020-02-12T22:56:39.779Z] 22:56:39 INFO - queue closed
[task 2020-02-12T22:56:39.968Z] 22:56:39 ERROR - Return code: 1
| 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.
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Description
•