Closed Bug 1835550 Opened 1 year ago Closed 11 months ago

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)

defect

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=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

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!

Flags: needinfo?(kshampur)
See Also: → 1835299
Summary: Perma [tier 2] beta OSX / Linux Btime raptor-browsertime Error: Browsertime failed to run | raptor-browsertime Critical: No data to collect → Perma [tier 2] OSX / Linux Btime raptor-browsertime Error: Browsertime failed to run | raptor-browsertime Critical: No data to collect

:nataliaCs, is it also a perma on mozilla-central?

Flags: needinfo?(ncsoregi)

Looks like a 50-50 situation after retriggers: push.

Should I file a separate bug for the intermittent issue?
Thank you.

Flags: needinfo?(ncsoregi) → needinfo?(gmierz2)

Yes please :) the issue in this bug is related to bug 1832290.

Flags: needinfo?(gmierz2)
See Also: → 1832290
Summary: Perma [tier 2] OSX / Linux Btime raptor-browsertime Error: Browsertime failed to run | raptor-browsertime Critical: No data to collect → Perma [tier 2] beta OSX / Linux Btime raptor-browsertime Error: Browsertime failed to run | raptor-browsertime Critical: No data to collect

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

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...

See Also: → 1832590
See Also: → 1863175
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.