Closed Bug 1838131 Opened 2 years ago Closed 2 years ago

Intermittent [tier 2] raptor-browsertime Critical: Browsertime process timed out after 621 seconds

Categories

(Testing :: Raptor, defect, P5)

Product:
Testing
Component:
Raptor
Type:
defect

Tracking

(Not tracked)

Status:
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=419070595&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/FCMDQbBkS26s5er12xcszQ/runs/0/artifacts/public/logs/live_backing.log

[task 2023-06-13T03:40:35.648Z] 03:40:35     INFO -  raptor-browsertime Info: Navigating to url about:blank iteration 1
[task 2023-06-13T03:40:41.729Z] 03:40:41     INFO -  raptor-browsertime Info: Cycle 0, waiting for 1000 ms
[task 2023-06-13T03:40:42.732Z] 03:40:42     INFO -  raptor-browsertime Info: Cycle 0, starting the measure
[task 2023-06-13T03:40:42.736Z] 03:40:42     INFO -  raptor-browsertime Info: Testing url http://127.0.0.1:40851/MotionMark/developer.html?test-interval=15&display=minimal&tiles=big&controller=fixed&frame-rate=30&kalman-process-error=1&kalman-measurement-error=4&time-measurement=performance&suite-name=Animometer&raptor=true&oskey=linux64 iteration 1
[task 2023-06-13T03:40:49.028Z] 03:40:49     INFO -  raptor-browsertime Info: CPU / Power usage: 11723
[task 2023-06-13T03:40:51.350Z] 03:40:51     INFO -  raptor-browsertime Info: Benchmark custom metric collection
[task 2023-06-13T03:40:51.399Z] 03:40:51     INFO -  raptor-browsertime Info: Waiting 3000 ms for data from benchmark...
<...>
[task 2023-06-13T03:50:50.607Z] 03:50:50     INFO -  raptor-browsertime Info: Waiting 3000 ms for data from benchmark...
[task 2023-06-13T03:50:52.188Z] 03:50:52 CRITICAL -  raptor-browsertime Critical: Browsertime process timed out after 621 seconds
[task 2023-06-13T03:50:52.188Z] 03:50:52     INFO -  raptor-perftest Info: Removing temporary directory: /tmp/tmp_gp89ej6
[task 2023-06-13T03:50:52.196Z] 03:50:52    ERROR -  Traceback (most recent call last):
[task 2023-06-13T03:50:52.196Z] 03:50:52     INFO -    File "/home/cltbld/tasks/task_168661878105705/build/tests/raptor/raptor/raptor.py", line 207, in <module>
[task 2023-06-13T03:50:52.196Z] 03:50:52     INFO -      main()
[task 2023-06-13T03:50:52.197Z] 03:50:52     INFO -    File "/home/cltbld/tasks/task_168661878105705/build/tests/raptor/raptor/raptor.py", line 153, in main
[task 2023-06-13T03:50:52.197Z] 03:50:52     INFO -      success = raptor.run_tests(raptor_test_list, raptor_test_names)
[task 2023-06-13T03:50:52.198Z] 03:50:52     INFO -    File "/home/cltbld/tasks/task_168661878105705/build/tests/raptor/raptor/perftest.py", line 478, in run_tests
[task 2023-06-13T03:50:52.198Z] 03:50:52     INFO -      self.run_test(test, timeout=int(test.get("page_timeout")))
[task 2023-06-13T03:50:52.198Z] 03:50:52     INFO -    File "/home/cltbld/tasks/task_168661878105705/build/tests/raptor/raptor/browsertime/base.py", line 850, in run_test
[task 2023-06-13T03:50:52.198Z] 03:50:52     INFO -      raise Exception(
[task 2023-06-13T03:50:52.199Z] 03:50:52     INFO -  Exception: Browsertime process timed out after 621 seconds
[task 2023-06-13T03:50:52.280Z] 03:50:52     INFO - Return code: 1
[task 2023-06-13T03:50:52.280Z] 03:50:52  WARNING - setting return code to 1
[task 2023-06-13T03:50:52.280Z] 03:50:52     INFO - Copying Raptor results to upload dir:
[task 2023-06-13T03:50:52.280Z] 03:50:52     INFO - /home/cltbld/tasks/task_168661878105705/build/blobber_upload_dir/perfherder-data.json
[task 2023-06-13T03:50:52.280Z] 03:50:52     INFO - Copying raptor results from /home/cltbld/tasks/task_168661878105705/build/raptor.json to /home/cltbld/tasks/task_168661878105705/build/blobber_upload_dir/perfherder-data.json
[task 2023-06-13T03:50:52.280Z] 03:50:52 CRITICAL - Error copying results /home/cltbld/tasks/task_168661878105705/build/raptor.json to upload dir /home/cltbld/tasks/task_168661878105705/build/blobber_upload_dir/perfherder-data.json
[task 2023-06-13T03:50:52.280Z] 03:50:52     INFO - [Errno 2] No such file or directory: '/home/cltbld/tasks/task_168661878105705/build/raptor.json'
[task 2023-06-13T03:50:52.281Z] 03:50:52     INFO - Running post-action listener: _package_coverage_data
[task 2023-06-13T03:50:52.281Z] 03:50:52     INFO - Running post-action listener: _resource_record_post_action
[task 2023-06-13T03:50:52.281Z] 03:50:52     INFO - Running post-action listener: process_java_coverage_data
[task 2023-06-13T03:50:52.281Z] 03:50:52     INFO - Running post-action listener: stop_device
[task 2023-06-13T03:50:52.281Z] 03:50:52     INFO - [mozharness: 2023-06-13 03:50:52.281710Z] Finished run-tests step (success)
[task 2023-06-13T03:50:52.281Z] 03:50:52     INFO - Running post-run listener: _resource_record_post_run
[task 2023-06-13T03:50:52.420Z] 03:50:52     INFO - Total resource usage - Wall time: 665s; CPU: 3%; Read bytes: 22781952; Write bytes: 1004314624; Read time: 472; Write time: 11316
[task 2023-06-13T03:50:52.420Z] 03:50:52     INFO - TinderboxPrint: CPU usage<br/>2.7%
[task 2023-06-13T03:50:52.420Z] 03:50:52     INFO - TinderboxPrint: I/O read bytes / time<br/>22,781,952 / 472
[task 2023-06-13T03:50:52.421Z] 03:50:52     INFO - TinderboxPrint: I/O write bytes / time<br/>1,004,314,624 / 11,316
[task 2023-06-13T03:50:52.421Z] 03:50:52     INFO - TinderboxPrint: CPU idle<br/>5,166.4 (97.3%)
[task 2023-06-13T03:50:52.421Z] 03:50:52     INFO - TinderboxPrint: CPU user<br/>118.2 (2.2%)
[task 2023-06-13T03:50:52.421Z] 03:50:52     INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2023-06-13T03:50:52.421Z] 03:50:52     INFO - install-chromium-distribution - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2023-06-13T03:50:52.422Z] 03:50:52     INFO - install - Wall time: 10s; CPU: 13%; Read bytes: 0; Write bytes: 19914752; Read time: 0; Write time: 132
[task 2023-06-13T03:50:52.444Z] 03:50:52     INFO - run-tests - Wall time: 655s; CPU: 3%; Read bytes: 22478848; Write bytes: 984129536; Read time: 464; Write time: 11176
[task 2023-06-13T03:50:52.727Z] 03:50:52  WARNING - returning nonzero exit status 1
[taskcluster 2023-06-13T03:50:52.770Z]    Exit Code: 1
[taskcluster 2023-06-13T03:50:52.770Z]    User Time: 1m41.174436s
[taskcluster 2023-06-13T03:50:52.770Z]  Kernel Time: 10.386278s
[taskcluster 2023-06-13T03:50:52.770Z]    Wall Time: 12m40.132194969s
[taskcluster 2023-06-13T03:50:52.770Z]       Result: FAILED
[taskcluster 2023-06-13T03:50:52.770Z] === Task Finished ===
[taskcluster 2023-06-13T03:50:52.770Z] Task Duration: 12m40.135583963s
[taskcluster 2023-06-13T03:50:52.894Z] Uploading artifact public/logs/localconfig.json from file logs/localconfig.json with content encoding "gzip", mime type "application/json" and expiry 2023-09-11T02:04:00.259Z
[taskcluster 2023-06-13T03:50:53.106Z] Uploading artifact public/test_info/resource-usage.json from file build/blobber_upload_dir/resource-usage.json with content encoding "gzip", mime type "application/json" and expiry 2023-09-11T02:04:00.259Z
[taskcluster 2023-06-13T03:50:53.285Z] Uploading link artifact public/logs/live.log to artifact public/logs/live_backing.log with expiry 2023-09-11T02:04:00.259Z
[taskcluster:error] exit status 1

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

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