Closed
Bug 1863175
Opened 11 months ago
Closed 11 months ago
Perma release OSX Btime raptor-browsertime Error: Browsertime failed to run | raptor-browsertime Critical: No data to collect
Categories
(Testing :: Raptor, defect, P5)
Testing
Raptor
Tracking
(Not tracked)
RESOLVED
FIXED
People
(Reporter: intermittent-bug-filer, Unassigned)
References
Details
(Keywords: intermittent-failure)
Filed by: imoraru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=435016495&repo=mozilla-release
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/enXgdH1gTQq2O7Eod3TP9g/runs/0/artifacts/public/logs/live_backing.log
[task 2023-11-04T23:17:04.043Z] 23:17:04 INFO - raptor-browsertime Info: browsertime_user_args: stat: path should be string, bytes, os.PathLike or integer, not list
[task 2023-11-04T23:17:04.044Z] 23:17:04 INFO - raptor-perftest Info: starting test: motionmark-animometer
[task 2023-11-04T23:17:04.044Z] 23:17:04 INFO - raptor-benchmark Info: bench_dir: /opt/worker/tasks/task_169913726957566/build/tests/raptor/raptor/tests/webkit/PerformanceTests
[task 2023-11-04T23:17:04.044Z] 23:17:04 INFO - raptor-benchmark Info: bench_dir contains:
[task 2023-11-04T23:17:04.045Z] 23:17:04 INFO - raptor-benchmark Info: [PosixPath('/opt/worker/tasks/task_169913726957566/build/tests/raptor/raptor/tests/webkit/PerformanceTests/six-speed'), PosixPath('/opt/worker/tasks/task_169913726957566/build/tests/raptor/raptor/tests/webkit/PerformanceTests/SunSpider'), PosixPath('/opt/worker/tasks/task_169913726957566/build/tests/raptor/raptor/tests/webkit/PerformanceTests/ARES-6'), PosixPath('/opt/worker/tasks/task_169913726957566/build/tests/raptor/raptor/tests/webkit/PerformanceTests/Speedometer'), PosixPath('/opt/worker/tasks/task_169913726957566/build/tests/raptor/raptor/tests/webkit/PerformanceTests/resources'), PosixPath('/opt/worker/tasks/task_169913726957566/build/tests/raptor/raptor/tests/webkit/PerformanceTests/StyleBench'), PosixPath('/opt/worker/tasks/task_169913726957566/build/tests/raptor/raptor/tests/webkit/PerformanceTests/MotionMark'), PosixPath('/opt/worker/tasks/task_169913726957566/build/tests/raptor/raptor/tests/webkit/PerformanceTests/wasm-godot'), PosixPath('/opt/worker/tasks/task_169913726957566/build/tests/raptor/raptor/tests/webkit/PerformanceTests/webaudio')]
[task 2023-11-04T23:17:04.045Z] 23:17:04 INFO - raptor-benchmark Info: starting webserver on '127.0.0.1:49352'
[task 2023-11-04T23:17:04.045Z] 23:17:04 INFO - raptor-benchmark Info: serving benchmarks from here: /opt/worker/tasks/task_169913726957566/build/tests/raptor/raptor/tests/webkit/PerformanceTests
[task 2023-11-04T23:17:04.047Z] 23:17:04 INFO - raptor-browsertime Info: test: {'here': '/opt/worker/tasks/task_169913726957566/build/tests/raptor/raptor/tests/benchmarks', 'alert_threshold': '2.0', 'apps': 'firefox, chrome, chromium, safari', 'expose_gecko_profiler': True, 'lower_is_better': False, 'page_cycles': '1', 'page_timeout': '600000', 'owner': ':jgilbert and Graphics(gfx) Team', 'test_url': 'http://127.0.0.1:49352/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=osx', 'type': 'benchmark', 'unit': 'score', 'name': 'motionmark-animometer', 'manifest': '/opt/worker/tasks/task_169913726957566/build/tests/raptor/raptor/tests/benchmarks/motionmark-animometer.ini', 'manifest_relpath': 'tests/benchmarks/motionmark-animometer.ini', 'path': '/opt/worker/tasks/task_169913726957566/build/tests/raptor/raptor/tests/benchmarks/motionmark-animometer', 'relpath': 'tests/benchmarks/motionmark-animometer', 'ancestor_manifest': 'raptor.ini', 'expected': 'pass', 'extra_profiler_run': True, 'extra_profiler_run_browser_cycles': 1, 'extra_profiler_run_page_cycles': 1, 'browser_cycles': 1, 'cold': False, 'expected_browser_cycles': 1, 'browser_cycle': 1}
[task 2023-11-04T23:17:04.047Z] 23:17:04 INFO - raptor-browsertime-desktop Info: binary_path: /opt/worker/tasks/task_169913726957566/build/application/Firefox.app/Contents/MacOS/firefox
[task 2023-11-04T23:17:04.047Z] 23:17:04 INFO - raptor-browsertime Info: timeout (s): 600000
[task 2023-11-04T23:17:04.047Z] 23:17:04 INFO - raptor-browsertime Info: browsertime cwd: /opt/worker/tasks/task_169913726957566/build
[task 2023-11-04T23:17:04.049Z] 23:17:04 INFO - raptor-browsertime Info: browsertime cmd: /opt/worker/tasks/task_169913726957566/fetches/node/bin/node /opt/worker/tasks/task_169913726957566/fetches/browsertime/node_modules/browsertime/bin/browsertime.js --firefox.geckodriverPath /opt/worker/tasks/task_169913726957566/fetches/geckodriver /opt/worker/tasks/task_169913726957566/build/tests/raptor/raptor/browsertime/../../browsertime/browsertime_benchmark.js --firefox.noDefaultPrefs --browsertime.page_cycle_delay 1000 --skipHar --pageLoadStrategy none --webdriverPageload true --firefox.disableBrowsertimeExtension true --pageCompleteCheckStartWait 5000 --pageCompleteCheckPollTimeout 1000 --beforePageCompleteWaitTime 2000 --timeouts.pageLoad 600000 --timeouts.script 600000 --browsertime.page_cycles 1 --pageCompleteWaitTime 5000 --browsertime.url http://127.0.0.1:49352/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=osx --browsertime.post_startup_delay 1000 --iterations 1 --browsertime.chimera false --browsertime.test_bytecode_cache false --firefox.perfStats false --browsertime.moz_fetch_dir /opt/worker/tasks/task_169913726957566/fetches --browsertime.expose_profiler false --browsertime.commands --viewPort 1280x1024 --browser firefox --firefox.binaryPath /opt/worker/tasks/task_169913726957566/build/application/Firefox.app/Contents/MacOS/firefox --resultDir /opt/worker/tasks/task_169913726957566/build/blobber_upload_dir/browsertime-results/motionmark-animometer --firefox.profileTemplate /var/folders/ql/m9jjtjgx7kv6lr6b4sg27tgr000014/T/tmpf8nspdzj/profile --video false --visualMetrics false
[task 2023-11-04T23:17:04.049Z] 23:17:04 INFO - raptor-browsertime Info: PATH: /opt/worker/tasks/task_169913726957566/build/venv/bin:/usr/local/bin:/usr/bin:/bin:/usr/sbin:/sbin
[task 2023-11-04T23:17:04.049Z] 23:17:04 INFO - raptor-browsertime Info: Calling browsertime with proc_timeout=621, and output_timeout=None
[task 2023-11-04T23:17:04.784Z] 23:17:04 INFO - raptor-browsertime Info: Running tests using Firefox - 1 iteration(s)
[task 2023-11-04T23:17:04.881Z] 23:17:04 INFO - raptor-browsertime Info: Skip setting default preferences for Firefox
[task 2023-11-04T23:17:07.485Z] 23:17:07 INFO - raptor-browsertime Info: firefox failed to start, trying 2 more time(s): Failed to decode response from marionette
[task 2023-11-04T23:17:07.485Z] 23:17:07 INFO - raptor-browsertime Info: Skip setting default preferences for Firefox
[task 2023-11-04T23:17:09.786Z] 23:17:09 INFO - raptor-browsertime Info: firefox failed to start, trying 1 more time(s): Failed to decode response from marionette
[task 2023-11-04T23:17:09.786Z] 23:17:09 INFO - raptor-browsertime Info: Skip setting default preferences for Firefox
[task 2023-11-04T23:17:12.089Z] 23:17:12 INFO - raptor-browsertime Info: firefox failed to start, trying 0 more time(s): Failed to decode response from marionette
[task 2023-11-04T23:17:12.089Z] 23:17:12 ERROR - raptor-browsertime Error: Browsertime failed to run
[task 2023-11-04T23:17:12.260Z] 23:17:12 INFO - raptor-browsertime Info: at SeleniumRunner.start (file:///opt/worker/tasks/task_169913726957566/fetches/browsertime/node_modules/browsertime/lib/core/seleniumRunner.js:86:13)
[task 2023-11-04T23:17:12.260Z] 23:17:12 INFO - raptor-browsertime Info: at processTicksAndRejections (node:internal/process/task_queues:96:5)
[task 2023-11-04T23:17:12.261Z] 23:17:12 INFO - raptor-browsertime Info: at async Iteration.run (file:///opt/worker/tasks/task_169913726957566/fetches/browsertime/node_modules/browsertime/lib/core/engine/iteration.js:116:7)
[task 2023-11-04T23:17:12.261Z] 23:17:12 INFO - raptor-browsertime Info: at async Engine.runByScript (file:///opt/worker/tasks/task_169913726957566/fetches/browsertime/node_modules/browsertime/lib/core/engine/index.js:304:20)
[task 2023-11-04T23:17:12.261Z] 23:17:12 INFO - raptor-browsertime Info: at async run (file:///opt/worker/tasks/task_169913726957566/fetches/browsertime/node_modules/browsertime/bin/browsertime.js:104:22)
[task 2023-11-04T23:17:12.261Z] 23:17:12 INFO - raptor-browsertime Info: at async file:///opt/worker/tasks/task_169913726957566/fetches/browsertime/node_modules/browsertime/bin/browsertime.js:217:1
[task 2023-11-04T23:17:12.261Z] 23:17:12 ERROR - raptor-browsertime Error: Browsertime failed to run
[task 2023-11-04T23:17:12.261Z] 23:17:12 CRITICAL - raptor-browsertime Critical: No data to collect
[task 2023-11-04T23:17:12.625Z] 23:17:12 INFO - raptor-perftest Info: Removing temporary directory: /var/folders/ql/m9jjtjgx7kv6lr6b4sg27tgr000014/T/tmpf8nspdzj
[task 2023-11-04T23:17:12.637Z] 23:17:12 ERROR - Traceback (most recent call last):
[task 2023-11-04T23:17:12.637Z] 23:17:12 INFO - File "/opt/worker/tasks/task_169913726957566/build/tests/raptor/raptor/raptor.py", line 190, in <module>
[task 2023-11-04T23:17:12.638Z] 23:17:12 INFO - main()
[task 2023-11-04T23:17:12.638Z] 23:17:12 INFO - File "/opt/worker/tasks/task_169913726957566/build/tests/raptor/raptor/raptor.py", line 136, in main
[task 2023-11-04T23:17:12.638Z] 23:17:12 INFO - success = raptor.run_tests(raptor_test_list, raptor_test_names)
[task 2023-11-04T23:17:12.638Z] 23:17:12 INFO - File "/opt/worker/tasks/task_169913726957566/build/tests/raptor/raptor/perftest.py", line 469, in run_tests
[task 2023-11-04T23:17:12.638Z] 23:17:12 INFO - self.run_test(test, timeout=int(test.get("page_timeout")))
[task 2023-11-04T23:17:12.638Z] 23:17:12 INFO - File "/opt/worker/tasks/task_169913726957566/build/tests/raptor/raptor/browsertime/base.py", line 938, in run_test
[task 2023-11-04T23:17:12.638Z] 23:17:12 INFO - raise Exception(self.browsertime_failure)
[task 2023-11-04T23:17:12.638Z] 23:17:12 INFO - Exception: No data to collect
[task 2023-11-04T23:17:12.671Z] 23:17:12 INFO - Return code: 1
[task 2023-11-04T23:17:12.671Z] 23:17:12 WARNING - setting return code to 1
[task 2023-11-04T23:17:12.671Z] 23:17:12 INFO - Copying Raptor results to upload dir:
[task 2023-11-04T23:17:12.671Z] 23:17:12 INFO - /opt/worker/tasks/task_169913726957566/build/blobber_upload_dir/perfherder-data.json
[task 2023-11-04T23:17:12.671Z] 23:17:12 INFO - Copying raptor results from /opt/worker/tasks/task_169913726957566/build/raptor.json to /opt/worker/tasks/task_169913726957566/build/blobber_upload_dir/perfherder-data.json
[task 2023-11-04T23:17:12.671Z] 23:17:12 CRITICAL - Error copying results /opt/worker/tasks/task_169913726957566/build/raptor.json to upload dir /opt/worker/tasks/task_169913726957566/build/blobber_upload_dir/perfherder-data.json
[task 2023-11-04T23:17:12.671Z] 23:17:12 INFO - [Errno 2] No such file or directory: '/opt/worker/tasks/task_169913726957566/build/raptor.json'
[task 2023-11-04T23:17:12.672Z] 23:17:12 INFO - Running post-action listener: _package_coverage_data
[task 2023-11-04T23:17:12.672Z] 23:17:12 INFO - Running post-action listener: _resource_record_post_action
[task 2023-11-04T23:17:12.672Z] 23:17:12 INFO - Running post-action listener: process_java_coverage_data
[task 2023-11-04T23:17:12.672Z] 23:17:12 INFO - Running post-action listener: stop_device
[task 2023-11-04T23:17:12.672Z] 23:17:12 INFO - [mozharness: 2023-11-04 23:17:12.672534Z] Finished run-tests step (success)
[task 2023-11-04T23:17:12.672Z] 23:17:12 INFO - Running post-run listener: _resource_record_post_run
[task 2023-11-04T23:17:12.736Z] 23:17:12 INFO - Total resource usage - Wall time: 71s; CPU: 9%; Read bytes: 65200128; Write bytes: 608481280; Read time: 1091; Write time: 1343
[task 2023-11-04T23:17:12.736Z] 23:17:12 INFO - TinderboxPrint: CPU usage<br/>8.8%
[task 2023-11-04T23:17:12.736Z] 23:17:12 INFO - TinderboxPrint: I/O read bytes / time<br/>65,200,128 / 1,091
[task 2023-11-04T23:17:12.736Z] 23:17:12 INFO - TinderboxPrint: I/O write bytes / time<br/>608,481,280 / 1,343
[task 2023-11-04T23:17:12.736Z] 23:17:12 INFO - TinderboxPrint: CPU idle<br/>778.3 (91.2%)
[task 2023-11-04T23:17:12.737Z] 23:17:12 INFO - TinderboxPrint: CPU system<br/>14.6 (1.7%)
[task 2023-11-04T23:17:12.737Z] 23:17:12 INFO - TinderboxPrint: CPU user<br/>60.2 (7.1%)
[task 2023-11-04T23:17:12.737Z] 23:17:12 INFO - TinderboxPrint: Swap in / out<br/>403,529,728 / 0
[task 2023-11-04T23:17:12.737Z] 23:17:12 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-11-04T23:17:12.737Z] 23:17:12 INFO - install - Wall time: 29s; CPU: 14%; Read bytes: 330053120; Write bytes: 327397376; Read time: 24068; Write time: 579
[task 2023-11-04T23:17:12.738Z] 23:17:12 INFO - run-tests - Wall time: 42s; CPU: 5%; Read bytes: 62619648; Write bytes: 248524800; Read time: 1024; Write time: 707
[task 2023-11-04T23:17:12.756Z] 23:17:12 WARNING - returning nonzero exit status 1
[taskcluster 2023-11-04T23:17:12.782Z] Exit Code: 1
[taskcluster 2023-11-04T23:17:12.782Z] User Time: 1m15.863864s
[taskcluster 2023-11-04T23:17:12.782Z] Kernel Time: 16.258699s
[taskcluster 2023-11-04T23:17:12.782Z] Wall Time: 2m49.221767s
[taskcluster 2023-11-04T23:17:12.782Z] Result: FAILED
[taskcluster 2023-11-04T23:17:12.782Z] === Task Finished ===
[taskcluster 2023-11-04T23:17:12.782Z] Task Duration: 2m49.227363s
[taskcluster 2023-11-04T23:17:12.881Z] Uploading artifact public/logs/localconfig.json from file /opt/worker/tasks/task_169913726957566/logs/localconfig.json with content encoding "gzip", mime type "application/json" and expiry 2024-02-02T21:22:51.424Z
[taskcluster 2023-11-04T23:17:13.188Z] Uploading artifact public/test_info/resource-usage.json from file /opt/worker/tasks/task_169913726957566/build/blobber_upload_dir/resource-usage.json with content encoding "gzip", mime type "application/json" and expiry 2024-02-02T21:22:51.424Z
[taskcluster 2023-11-04T23:17:13.450Z] Uploading link artifact public/logs/live.log to artifact public/logs/live_backing.log with expiry 2024-02-02T21:22:51.424Z
[taskcluster:error] exit status 1
|
||
Comment 1•11 months ago
|
||
Last green job was on this push , before filing this bug I've retriggered that job and now it failed.
Here is a range from the last passed job to the first perma failure. And here are all the browser-time jobs that passed and failed on OSX from the push where we found this failure.
Judging by what was happening with Bug 1835550, maybe, in a day or two, this jobs will also be green here too. I will retrigger the jobs in 4-5 hours to see what happens then(maybe it was a hiccup). If they will turn green, I will come back to leave a comment.
Hi Greg! Can you please take a look at this?
Thank you!
Flags: needinfo?(gmierz2)
|
|
||
Comment 2•11 months ago
|
||
So, I've retriggered all failed jobs after 5 hours as I said, and they are all green now.
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
|
||
Comment 5•11 months ago
|
||
Thank you for retriggering them Iulian! I see that they were passing yesterday too: https://treeherder.mozilla.org/jobs?repo=mozilla-release&searchStr=browsertime&revision=b8f0d32ac6a5c34db8692ed382c3018e6309ea09
Flags: needinfo?(gmierz2)
|
||
Updated•11 months ago
|
Status: NEW → RESOLVED
Closed: 11 months ago
Resolution: --- → FIXED
You need to log in
before you can comment on or make changes to this bug.
Description
•