Closed Bug 1554067 Opened 6 years ago Closed 6 years ago

Intermittent twinopen | timeout

Categories

(Testing :: Talos, defect, P5)

Version 3
defect

Tracking

(Not tracked)

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure, regression)

Filed by: csabou [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=248132527&repo=mozilla-beta
Full log: https://queue.taskcluster.net/v1/task/HI0LLBkJTW6OsKx3tWHQqg/runs/0/artifacts/public/logs/live_backing.log


06:07:31 INFO - TEST-INFO | started process 8038 (/home/cltbld/tasks/task_1558677916/build/application/firefox/firefox -profile /tmp/tmpt1MLgt/profile)
06:07:31 INFO - PID 8038 | ATTENTION: default value of option force_s3tc_enable overridden by environment.
06:07:31 INFO - PID 8038 | ATTENTION: default value of option force_s3tc_enable overridden by environment.
06:07:37 INFO - PID 8038 | Cycle 1(1): loaded ext+twinopen:twinopen.html (next: ext+twinopen:twinopen.html)
06:07:39 INFO - PID 8038 | Cycle 1(2): loaded ext+twinopen:twinopen.html (next: ext+twinopen:twinopen.html)
06:07:42 INFO - PID 8038 | Cycle 1(3): loaded ext+twinopen:twinopen.html (next: ext+twinopen:twinopen.html)
06:07:44 INFO - PID 8038 | Cycle 1(4): loaded ext+twinopen:twinopen.html (next: ext+twinopen:twinopen.html)
06:07:46 INFO - PID 8038 | Cycle 1(5): loaded ext+twinopen:twinopen.html (next: ext+twinopen:twinopen.html)
06:07:48 INFO - PID 8038 | Cycle 1(6): loaded ext+twinopen:twinopen.html (next: ext+twinopen:twinopen.html)
06:07:51 INFO - PID 8038 | Cycle 1(7): loaded ext+twinopen:twinopen.html (next: ext+twinopen:twinopen.html)
06:07:53 INFO - PID 8038 | Cycle 1(8): loaded ext+twinopen:twinopen.html (next: ext+twinopen:twinopen.html)
06:07:55 INFO - PID 8038 | Cycle 1(9): loaded ext+twinopen:twinopen.html (next: ext+twinopen:twinopen.html)
06:07:57 INFO - PID 8038 | Cycle 1(10): loaded ext+twinopen:twinopen.html (next: ext+twinopen:twinopen.html)
06:08:00 INFO - PID 8038 | Cycle 1(11): loaded ext+twinopen:twinopen.html (next: ext+twinopen:twinopen.html)
06:08:02 INFO - PID 8038 | Cycle 1(12): loaded ext+twinopen:twinopen.html (next: ext+twinopen:twinopen.html)
06:08:04 INFO - PID 8038 | Cycle 1(13): loaded ext+twinopen:twinopen.html (next: ext+twinopen:twinopen.html)
06:08:07 INFO - PID 8038 | Cycle 1(14): loaded ext+twinopen:twinopen.html (next: ext+twinopen:twinopen.html)
06:08:09 INFO - PID 8038 | Cycle 1(15): loaded ext+twinopen:twinopen.html (next: ext+twinopen:twinopen.html)
06:08:11 INFO - PID 8038 | Cycle 1(16): loaded ext+twinopen:twinopen.html (next: ext+twinopen:twinopen.html)
06:08:13 INFO - PID 8038 | Cycle 1(17): loaded ext+twinopen:twinopen.html (next: ext+twinopen:twinopen.html)
06:12:31 INFO - Timeout waiting for test completion; killing browser...
06:12:31 INFO - Terminating psutil.Process(pid=8038, name='firefox-bin', started='06:07:31')
06:12:31 INFO - PID 8038 | ExceptionHandler::GenerateDump cloned child 9001
06:12:31 INFO - PID 8038 | ExceptionHandler::SendContinueSignalToChild sent continue signal to child
06:12:31 INFO - PID 8038 | ExceptionHandler::WaitForContinueSignal waiting for continue signal...
06:12:31 INFO - PID 8038 | Exiting due to channel error.
06:12:31 INFO - PID 8038 | [GFX1-]: Receive IPC close with reason=AbnormalShutdown
06:12:31 INFO - PID 8038 | [GFX1-]: Receive IPC close with reason=AbnormalShutdown
06:12:31 INFO - PID 8038 | [Child 8948, Chrome_ChildThread] WARNING: pipe error (3): Connection reset by peer: file /builds/worker/workspace/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 358
06:12:31 INFO - PID 8038 | Exiting due to channel error.
06:12:31 INFO - PID 8038 | Exiting due to channel error.
06:12:31 INFO - PID 8038 | [Child 8911, Chrome_ChildThread] WARNING: pipe error (3): Connection reset by peer: file /builds/worker/workspace/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 358
06:12:31 INFO - PID 8038 | Exiting due to channel error.
06:12:31 INFO - TEST-UNEXPECTED-ERROR | twinopen | timeout
06:12:31 ERROR - Traceback (most recent call last):
06:12:31 INFO - File "/home/cltbld/tasks/task_1558677916/build/tests/talos/talos/run_tests.py", line 300, in run_tests
06:12:31 INFO - talos_results.add(mytest.runTest(browser_config, test))
06:12:31 INFO - File "/home/cltbld/tasks/task_1558677916/build/tests/talos/talos/ttest.py", line 64, in runTest
06:12:31 INFO - return self._runTest(browser_config, test_config, setup)
06:12:31 INFO - File "/home/cltbld/tasks/task_1558677916/build/tests/talos/talos/ttest.py", line 215, in _runTest
06:12:31 INFO - debugger_args=browser_config['debugger_args']
06:12:31 INFO - File "/home/cltbld/tasks/task_1558677916/build/tests/talos/talos/talos_process.py", line 143, in run_browser
06:12:31 INFO - raise TalosError("timeout")
06:12:31 INFO - TalosError: timeout
06:12:31 INFO - TEST-INFO took 302881ms
06:12:31 INFO - SUITE-END | took 400s
06:12:31 ERROR - Return code: 2
06:12:31 WARNING - setting return code to 2
06:12:31 ERROR - # TBPL FAILURE #
06:12:31 INFO - Running post-action listener: _package_coverage_data
06:12:31 INFO - Running post-action listener: _resource_record_post_action
06:12:31 INFO - Running post-action listener: process_java_coverage_data
06:12:31 INFO - [mozharness: 2019-05-24 06:12:31.913004Z] Finished run-tests step (success)
06:12:31 INFO - Running post-run listener: _resource_record_post_run
06:12:31 INFO - Total resource usage - Wall time: 407s; CPU: 5.0%; Read bytes: 40861696; Write bytes: 1058398208; Read time: 760; Write time: 76104
06:12:31 INFO - TinderboxPrint: CPU usage<br/>4.6%
06:12:31 INFO - TinderboxPrint: I/O read bytes / time<br/>40,861,696 / 760
06:12:31 INFO - TinderboxPrint: I/O write bytes / time<br/>1,058,398,208 / 76,104
06:12:31 INFO - TinderboxPrint: CPU idle<br/>3,080.5 (95.4%)
06:12:31 INFO - TinderboxPrint: CPU user<br/>122.5 (3.8%)
06:12:31 INFO - TinderboxPrint: Swap in / out<br/>0 / 0
06:12:31 INFO - install - Wall time: 6s; CPU: 13.0%; Read bytes: 376832; Write bytes: 2211840; Read time: 0; Write time: 8
06:12:31 INFO - setup-mitmproxy - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
06:12:31 INFO - run-tests - Wall time: 401s; CPU: 4.0%; Read bytes: 36511744; Write bytes: 1051213824; Read time: 728; Write time: 75832
06:12:32 WARNING - returning nonzero exit status 2

Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE
See Also: → 1661417
You need to log in before you can comment on or make changes to this bug.