Perma [tier 2] beta OSX / Linux Btime raptor-browsertime Error: Browsertime failed to run | raptor-browsertime Critical: No data to collect
Categories
(Testing :: Raptor, defect, P5)
Tracking
(Not tracked)
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=417340818&repo=mozilla-beta
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/NRbEvfl9TJWLBQISquYyzQ/runs/0/artifacts/public/logs/live_backing.log
[task 2023-05-28T19:44:18.817Z] 19:44:18 INFO - raptor-browsertime-desktop Info: binary_path: /home/cltbld/tasks/task_168530293404355/build/application/firefox/firefox
[task 2023-05-28T19:44:18.817Z] 19:44:18 INFO - raptor-browsertime Info: timeout (s): 180000
[task 2023-05-28T19:44:18.818Z] 19:44:18 INFO - raptor-browsertime Info: browsertime cwd: /home/cltbld/tasks/task_168530293404355/build
[task 2023-05-28T19:44:18.820Z] 19:44:18 INFO - raptor-browsertime Info: browsertime cmd: /home/cltbld/tasks/task_168530293404355/fetches/node/bin/node /home/cltbld/tasks/task_168530293404355/fetches/browsertime/node_modules/browsertime/bin/browsertime.js --firefox.geckodriverPath /home/cltbld/tasks/task_168530293404355/fetches/geckodriver /home/cltbld/tasks/task_168530293404355/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 180000 --timeouts.script 900000 --browsertime.page_cycles 5 --pageCompleteWaitTime 5000 --browsertime.url http://127.0.0.1:53419/Speedometer/index.html?raptor --browsertime.post_startup_delay 1000 --iterations 1 --videoParams.androidVideoWaitTime 20000 --browsertime.chimera false --browsertime.test_bytecode_cache false --firefox.perfStats false --browsertime.moz_fetch_dir /home/cltbld/tasks/task_168530293404355/fetches --browsertime.expose_profiler false --browsertime.commands --viewPort 1280x1024 --browser firefox --firefox.binaryPath /home/cltbld/tasks/task_168530293404355/build/application/firefox/firefox --resultDir /home/cltbld/tasks/task_168530293404355/build/blobber_upload_dir/browsertime-results/speedometer --firefox.profileTemplate /tmp/tmpkb2a7z6m/profile --video false --visualMetrics false
[task 2023-05-28T19:44:18.821Z] 19:44:18 INFO - raptor-browsertime Info: PATH: /home/cltbld/tasks/task_168530293404355/build/venv/bin:/bin:/sbin:/usr/bin:/usr/sbin:/usr/local/bin
[task 2023-05-28T19:44:18.821Z] 19:44:18 INFO - raptor-browsertime Info: Calling browsertime with proc_timeout=921, and output_timeout=None
[task 2023-05-28T19:44:19.558Z] 19:44:19 INFO - raptor-browsertime Info: Running tests using Firefox - 1 iteration(s)
[task 2023-05-28T19:44:19.584Z] 19:44:19 INFO - raptor-browsertime Info: Skip setting default preferences for Firefox
[task 2023-05-28T19:44:21.580Z] 19:44:21 INFO - raptor-browsertime Info: firefox failed to start, trying 2 more time(s): Failed to decode response from marionette
[task 2023-05-28T19:44:21.581Z] 19:44:21 INFO - raptor-browsertime Info: Skip setting default preferences for Firefox
[task 2023-05-28T19:44:23.478Z] 19:44:23 INFO - raptor-browsertime Info: firefox failed to start, trying 1 more time(s): Failed to decode response from marionette
[task 2023-05-28T19:44:23.478Z] 19:44:23 INFO - raptor-browsertime Info: Skip setting default preferences for Firefox
[task 2023-05-28T19:44:25.364Z] 19:44:25 INFO - raptor-browsertime Info: firefox failed to start, trying 0 more time(s): Failed to decode response from marionette
[task 2023-05-28T19:44:25.365Z] 19:44:25 ERROR - raptor-browsertime Error: Browsertime failed to run
[task 2023-05-28T19:44:25.385Z] 19:44:25 INFO - raptor-browsertime Info: at SeleniumRunner.start (file:///home/cltbld/tasks/task_168530293404355/fetches/browsertime/node_modules/browsertime/lib/core/seleniumRunner.js:86:13)
[task 2023-05-28T19:44:25.385Z] 19:44:25 INFO - raptor-browsertime Info: at processTicksAndRejections (node:internal/process/task_queues:96:5)
[task 2023-05-28T19:44:25.386Z] 19:44:25 INFO - raptor-browsertime Info: at async Iteration.run (file:///home/cltbld/tasks/task_168530293404355/fetches/browsertime/node_modules/browsertime/lib/core/engine/iteration.js:116:7)
[task 2023-05-28T19:44:25.386Z] 19:44:25 INFO - raptor-browsertime Info: at async Engine.runByScript (file:///home/cltbld/tasks/task_168530293404355/fetches/browsertime/node_modules/browsertime/lib/core/engine/index.js:304:20)
[task 2023-05-28T19:44:25.387Z] 19:44:25 INFO - raptor-browsertime Info: at async run (file:///home/cltbld/tasks/task_168530293404355/fetches/browsertime/node_modules/browsertime/bin/browsertime.js:104:22)
[task 2023-05-28T19:44:25.387Z] 19:44:25 INFO - raptor-browsertime Info: at async file:///home/cltbld/tasks/task_168530293404355/fetches/browsertime/node_modules/browsertime/bin/browsertime.js:195:1
[task 2023-05-28T19:44:25.387Z] 19:44:25 ERROR - raptor-browsertime Error: Browsertime failed to run
[task 2023-05-28T19:44:25.388Z] 19:44:25 CRITICAL - raptor-browsertime Critical: No data to collect
[task 2023-05-28T19:44:25.388Z] 19:44:25 INFO - raptor-perftest Info: Removing temporary directory: /tmp/tmpkb2a7z6m
[task 2023-05-28T19:44:25.396Z] 19:44:25 ERROR - Traceback (most recent call last):
[task 2023-05-28T19:44:25.396Z] 19:44:25 INFO - File "/home/cltbld/tasks/task_168530293404355/build/tests/raptor/raptor/raptor.py", line 204, in <module>
[task 2023-05-28T19:44:25.396Z] 19:44:25 INFO - main()
[task 2023-05-28T19:44:25.396Z] 19:44:25 INFO - File "/home/cltbld/tasks/task_168530293404355/build/tests/raptor/raptor/raptor.py", line 150, in main
[task 2023-05-28T19:44:25.397Z] 19:44:25 INFO - success = raptor.run_tests(raptor_test_list, raptor_test_names)
[task 2023-05-28T19:44:25.397Z] 19:44:25 INFO - File "/home/cltbld/tasks/task_168530293404355/build/tests/raptor/raptor/perftest.py", line 472, in run_tests
[task 2023-05-28T19:44:25.397Z] 19:44:25 INFO - self.run_test(test, timeout=int(test.get("page_timeout")))
[task 2023-05-28T19:44:25.398Z] 19:44:25 INFO - File "/home/cltbld/tasks/task_168530293404355/build/tests/raptor/raptor/browsertime/base.py", line 845, in run_test
[task 2023-05-28T19:44:25.398Z] 19:44:25 INFO - raise Exception(self.browsertime_failure)
[task 2023-05-28T19:44:25.398Z] 19:44:25 INFO - Exception: No data to collect
[task 2023-05-28T19:44:25.479Z] 19:44:25 INFO - Return code: 1
[task 2023-05-28T19:44:25.479Z] 19:44:25 WARNING - setting return code to 1
[task 2023-05-28T19:44:25.479Z] 19:44:25 INFO - Copying Raptor results to upload dir:
[task 2023-05-28T19:44:25.479Z] 19:44:25 INFO - /home/cltbld/tasks/task_168530293404355/build/blobber_upload_dir/perfherder-data.json
[task 2023-05-28T19:44:25.479Z] 19:44:25 INFO - Copying raptor results from /home/cltbld/tasks/task_168530293404355/build/raptor.json to /home/cltbld/tasks/task_168530293404355/build/blobber_upload_dir/perfherder-data.json
[task 2023-05-28T19:44:25.479Z] 19:44:25 CRITICAL - Error copying results /home/cltbld/tasks/task_168530293404355/build/raptor.json to upload dir /home/cltbld/tasks/task_168530293404355/build/blobber_upload_dir/perfherder-data.json
[task 2023-05-28T19:44:25.479Z] 19:44:25 INFO - [Errno 2] No such file or directory: '/home/cltbld/tasks/task_168530293404355/build/raptor.json'
[task 2023-05-28T19:44:25.480Z] 19:44:25 INFO - Running post-action listener: _package_coverage_data
[task 2023-05-28T19:44:25.480Z] 19:44:25 INFO - Running post-action listener: _resource_record_post_action
[task 2023-05-28T19:44:25.480Z] 19:44:25 INFO - Running post-action listener: process_java_coverage_data
[task 2023-05-28T19:44:25.480Z] 19:44:25 INFO - Running post-action listener: stop_device
[task 2023-05-28T19:44:25.480Z] 19:44:25 INFO - [mozharness: 2023-05-28 19:44:25.480771Z] Finished run-tests step (success)
[task 2023-05-28T19:44:25.480Z] 19:44:25 INFO - Running post-run listener: _resource_record_post_run
[task 2023-05-28T19:44:25.555Z] 19:44:25 INFO - Total resource usage - Wall time: 49s; CPU: 7%; Read bytes: 15728640; Write bytes: 725860352; Read time: 328; Write time: 9016
[task 2023-05-28T19:44:25.555Z] 19:44:25 INFO - TinderboxPrint: CPU usage<br/>6.8%
[task 2023-05-28T19:44:25.555Z] 19:44:25 INFO - TinderboxPrint: I/O read bytes / time<br/>15,728,640 / 328
[task 2023-05-28T19:44:25.555Z] 19:44:25 INFO - TinderboxPrint: I/O write bytes / time<br/>725,860,352 / 9,016
[task 2023-05-28T19:44:25.555Z] 19:44:25 INFO - TinderboxPrint: CPU idle<br/>364.3 (92.7%)
[task 2023-05-28T19:44:25.555Z] 19:44:25 INFO - TinderboxPrint: CPU system<br/>4.1 (1.1%)
[task 2023-05-28T19:44:25.555Z] 19:44:25 INFO - TinderboxPrint: CPU user<br/>22.1 (5.6%)
[task 2023-05-28T19:44:25.555Z] 19:44:25 INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2023-05-28T19:44:25.556Z] 19:44:25 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-05-28T19:44:25.556Z] 19:44:25 INFO - install - Wall time: 9s; CPU: 13%; Read bytes: 0; Write bytes: 25985024; Read time: 0; Write time: 92
[task 2023-05-28T19:44:25.557Z] 19:44:25 INFO - run-tests - Wall time: 40s; CPU: 5%; Read bytes: 15679488; Write bytes: 699875328; Read time: 328; Write time: 8924
[task 2023-05-28T19:44:25.582Z] 19:44:25 WARNING - returning nonzero exit status 1
[taskcluster 2023-05-28T19:44:25.616Z] Exit Code: 1
[taskcluster 2023-05-28T19:44:25.616Z] User Time: 1m33.910682s
[taskcluster 2023-05-28T19:44:25.616Z] Kernel Time: 8.935968s
[taskcluster 2023-05-28T19:44:25.616Z] Wall Time: 2m10.600236063s
[taskcluster 2023-05-28T19:44:25.616Z] Result: FAILED
[taskcluster 2023-05-28T19:44:25.616Z] === Task Finished ===
[taskcluster 2023-05-28T19:44:25.616Z] Task Duration: 2m10.603697693s
[taskcluster 2023-05-28T19:44:25.713Z] Uploading artifact public/logs/localconfig.json from file logs/localconfig.json with content encoding "gzip", mime type "application/json" and expiry 2023-08-26T18:02:24.950Z
[taskcluster 2023-05-28T19:44:25.931Z] 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-08-26T18:02:24.950Z
[taskcluster 2023-05-28T19:44:26.057Z] Uploading link artifact public/logs/live.log to artifact public/logs/live_backing.log with expiry 2023-08-26T18:02:24.950Z
[taskcluster:error] exit status 1
Comment 1•2 years ago
•
|
||
This is now permafailing on mozilla-beta, this happens even where the test was green before. This seems to have started here:
Hi Kash! Can you please take a look at this?
Thank you!
| Comment hidden (Intermittent Failures Robot) |
Comment 3•2 years ago
|
||
I've re triggered a few runs and they seem to be passing now.
Comment 4•2 years ago
|
||
The failure appears on mozilla-central as well: https://treeherder.mozilla.org/jobs?repo=mozilla-central&group_state=expanded&revision=0ea1f0bff41ab8b0e92e4f35f3d6eaf801ad3fc0&searchStr=OS%2CX%2C10.15%2CWebRender%2CShippable%2Cbrowsertime&selectedTaskRun=KQyQ9W0cSxycu6tc6rf4Rg.0
Comment 5•2 years ago
|
||
:nataliaCs, is it also a perma on mozilla-central?
Updated•2 years ago
|
Comment 6•2 years ago
|
||
Looks like a 50-50 situation after retriggers: push.
Should I file a separate bug for the intermittent issue?
Thank you.
Comment 7•2 years ago
|
||
Yes please :) the issue in this bug is related to bug 1832290.
Updated•2 years ago
|
Comment 8•2 years ago
|
||
I see that central failure is for Safari, which has it's own intermittent problems, and might be resolved with saf upgrades. bug 1802922, comment 2
| Comment hidden (Intermittent Failures Robot) |
Comment 10•2 years ago
•
|
||
This is still happening on beta and the difference from the last time is that now, this is affecting multiple jobs, not just the sp job: https://treeherder.mozilla.org/jobs?repo=mozilla-beta&group_state=expanded&resultStatus=success%2Cpending%2Crunning%2Ctestfailed%2Cbusted%2Cexception%2Crunnable&searchStr=linux%2C18.04%2Cx64%2Cwebrender%2Cshippable%2Cbrowser%2Ctime&revision=eb0e5efeb4144e02db4898c481ab299e4ffbe5a5&selectedTaskRun=bMYLCJmGSkm8UT-xOxXrCg.0
| Comment hidden (Intermittent Failures Robot) |
Comment 12•2 years ago
•
|
||
Looks like they are passing again, a day later?
https://treeherder.mozilla.org/jobs?repo=mozilla-beta&searchStr=benchmark%2C&revision=5f036ce2680a08b950cbfadd770beba129cbb195&selectedTaskRun=FyDU6M9eTICkLRgpNpUs6A.0
this is more like an intermittent-perma?
We have bug 1832590 filed which would help investigate this in CI. until then i think this error will keep appearing and disappearing after a few days like it did just now and last week...
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Updated•2 years ago
|
Description
•