1865770 - Perma Btime raptor-browsertime Error: Browsertime failed to run | raptor-browsertime Critical: Failed waiting on page http://127.0.0.1:49958/unity-webgl/index.html?raptor to finished loading, timed out after 120000 ms UnexpectedAlertOpenError:

Status: RESOLVED FIXED

(Testing :: Raptor, defect)

Description

[Treeherder Bug Filer]

Filed by: sstanca [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=436988861&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/YUywwG1oSjKJivhvAsbBHA/runs/0/artifacts/public/logs/live_backing.log

---

[task 2023-11-21T04:24:49.486Z] 04:24:49     INFO -  Turn off this advice by setting config variable advice.detachedHead to false
[task 2023-11-21T04:24:49.487Z] 04:24:49     INFO -  HEAD is now at 61332db5 Add a twitch animation benchmark (#31)
[task 2023-11-21T04:24:49.545Z] 04:24:49     INFO -  raptor-benchmark Info: bench_dir: C:\Users\task_1700538604\build\tests\raptor\raptor\tests\webkit\PerformanceTests\unity-webgl
[task 2023-11-21T04:24:49.546Z] 04:24:49     INFO -  raptor-benchmark Info: bench_dir contains:
[task 2023-11-21T04:24:49.546Z] 04:24:49     INFO -  raptor-benchmark Info: [WindowsPath('C:/Users/task_1700538604/build/tests/raptor/raptor/tests/webkit/PerformanceTests/unity-webgl/unity-webgl')]
[task 2023-11-21T04:24:49.547Z] 04:24:49     INFO -  raptor-benchmark Info: starting webserver on '127.0.0.1:49958'
[task 2023-11-21T04:24:49.547Z] 04:24:49     INFO -  raptor-benchmark Info: serving benchmarks from here: C:\Users\task_1700538604\build\tests\raptor\raptor\tests\webkit\PerformanceTests\unity-webgl
[task 2023-11-21T04:24:49.552Z] 04:24:49     INFO -  raptor-browsertime Info: test: {'here': 'C:\\Users\\task_1700538604\\build\\tests\\raptor\\raptor\\tests\\benchmarks', 'alert_threshold': '2.0', 'apps': 'firefox, chrome, chromium, safari', 'expose_browser_profiler': True, 'lower_is_better': False, 'owner': ':jgilbert and Graphics(gfx) Team', 'page_cycles': '5', 'page_timeout': '420000', 'test_url': 'http://127.0.0.1:49958/unity-webgl/index.html?raptor', 'type': 'benchmark', 'unit': 'score', 'repository': 'https://github.com/mozilla/perf-automation', 'repository_revision': '61332db584026b73e37066d717a162825408c36b', 'repository_path': 'benchmarks/unity-webgl', 'name': 'unity-webgl', 'manifest': 'C:\\Users\\task_1700538604\\build\\tests\\raptor\\raptor\\tests\\benchmarks\\unity-webgl-desktop.ini', 'manifest_relpath': 'tests\\benchmarks\\unity-webgl-desktop.ini', 'path': 'C:\\Users\\task_1700538604\\build\\tests\\raptor\\raptor\\tests\\benchmarks\\unity-webgl', 'relpath': 'tests\\benchmarks\\unity-webgl', '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-21T04:24:49.552Z] 04:24:49     INFO -  raptor-browsertime-desktop Info: binary_path: C:\Users\task_1700538604\build\application\firefox\firefox.exe
[task 2023-11-21T04:24:49.553Z] 04:24:49     INFO -  raptor-browsertime Info: timeout (s): 420000
[task 2023-11-21T04:24:49.553Z] 04:24:49     INFO -  raptor-browsertime Info: browsertime cwd: C:\Users\task_1700538604\build
[task 2023-11-21T04:24:49.555Z] 04:24:49     INFO -  raptor-browsertime Info: browsertime cmd: C:/Users/task_1700538604/fetches/node/node.exe C:/Users/task_1700538604/fetches/browsertime/node_modules/browsertime/bin/browsertime.js --firefox.geckodriverPath C:/Users/task_1700538604/fetches/geckodriver.exe C:\Users\task_1700538604\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 420000 --timeouts.script 2100000 --browsertime.page_cycles 5 --pageCompleteWaitTime 5000 --browsertime.url http://127.0.0.1:49958/unity-webgl/index.html?raptor --browsertime.post_startup_delay 30000 --iterations 1 --browsertime.chimera false --browsertime.test_bytecode_cache false --firefox.perfStats false --browsertime.moz_fetch_dir C:/Users/task_1700538604/fetches --browsertime.expose_profiler false --browsertime.commands  --viewPort 1280x1024 --browser firefox --firefox.binaryPath C:\Users\task_1700538604\build\application\firefox\firefox.exe --resultDir C:\Users\task_1700538604\build\blobber_upload_dir\browsertime-results\unity-webgl --firefox.profileTemplate C:\Users\task_1700538604\AppData\Local\Temp\tmpshexbbgr.mozrunner --video false --visualMetrics false
[task 2023-11-21T04:24:49.557Z] 04:24:49     INFO -  raptor-browsertime Info: PATH: C:\Users\task_1700538604\build\venv\Scripts;C:\windows\system32;C:\windows;C:\windows\System32\Wbem;C:\windows\System32\WindowsPowerShell\v1.0\;C:\windows\System32\OpenSSH\;C:\Program Files\Puppet Labs\Puppet\bin;C:\Program Files\Mellanox\MLNX_VPI\IB\Tools;C:\Program Files\Mellanox\MLNX_CIMProvider\lib\mft;C:\Program Files\Git\cmd;C:\Program Files (x86)\GNU\GnuPG\pub;C:\Program Files (x86)\Windows Kits\10\Windows Performance Toolkit\;C:\Program Files\Mercurial\;C:\Program Files\Mercurial;C:\mozilla-build\bin;C:\mozilla-build\kdiff;C:\mozilla-build\moztools-x64\bin;C:\mozilla-build\mozmake;C:\mozilla-build\nsis-3.01;C:\mozilla-build\python;C:\mozilla-build\python\Scripts;C:\mozilla-build\python3;C:\mozilla-build\msys\bin;C:\mozilla-build\msys\local\bin;C:\Users\task_1700538604\AppData\Local\Microsoft\WindowsApps
[task 2023-11-21T04:24:49.557Z] 04:24:49     INFO -  raptor-browsertime Info: Calling browsertime with proc_timeout=2150, and output_timeout=None
[task 2023-11-21T04:24:50.456Z] 04:24:50     INFO -  raptor-browsertime Info: Running tests using Firefox - 1 iteration(s)
[task 2023-11-21T04:24:50.459Z] 04:24:50     INFO -  raptor-browsertime Info: Skip setting default preferences for Firefox
[task 2023-11-21T04:24:53.210Z] 04:24:53     INFO -  raptor-browsertime Info: Starting a browsertime benchamrk
[task 2023-11-21T04:24:53.210Z] 04:24:53     INFO -  raptor-browsertime Info: Waiting for 30000 ms (post_startup_delay)
[task 2023-11-21T04:25:23.211Z] 04:25:23     INFO -  raptor-browsertime Info: Navigating to about:blank
[task 2023-11-21T04:25:23.211Z] 04:25:23     INFO -  raptor-browsertime Info: Navigating to url about:blank iteration 1
[task 2023-11-21T04:25:29.246Z] 04:25:29     INFO -  raptor-browsertime Info: Cycle 0, waiting for 1000 ms
[task 2023-11-21T04:25:30.247Z] 04:25:30     INFO -  raptor-browsertime Info: Cycle 0, starting the measure
[task 2023-11-21T04:25:30.248Z] 04:25:30     INFO -  raptor-browsertime Info: Testing url http://127.0.0.1:49958/unity-webgl/index.html?raptor iteration 1
[task 2023-11-21T04:25:35.322Z] 04:25:35    ERROR -  raptor-browsertime Error: Browsertime failed to run
[task 2023-11-21T04:25:35.322Z] 04:25:35     INFO -  raptor-browsertime Info:     at Object.throwDecodedError (C:\Users\task_1700538604\fetches\browsertime\node_modules\selenium-webdriver\lib\error.js:524:15)
[task 2023-11-21T04:25:35.322Z] 04:25:35     INFO -  raptor-browsertime Info:     at parseHttpResponse (C:\Users\task_1700538604\fetches\browsertime\node_modules\selenium-webdriver\lib\http.js:601:13)
[task 2023-11-21T04:25:35.323Z] 04:25:35     INFO -  raptor-browsertime Info:     at Executor.execute (C:\Users\task_1700538604\fetches\browsertime\node_modules\selenium-webdriver\lib\http.js:529:28)
[task 2023-11-21T04:25:35.323Z] 04:25:35     INFO -  raptor-browsertime Info:     at processTicksAndRejections (node:internal/process/task_queues:96:5)
[task 2023-11-21T04:25:35.324Z] 04:25:35     INFO -  raptor-browsertime Info:     at async Driver.execute (C:\Users\task_1700538604\fetches\browsertime\node_modules\selenium-webdriver\lib\webdriver.js:745:17)
[task 2023-11-21T04:25:35.335Z] 04:25:35 CRITICAL -  raptor-browsertime Critical: Failed waiting on page http://127.0.0.1:49958/unity-webgl/index.html?raptor to finished loading, timed out after 120000 ms UnexpectedAlertOpenError: Dismissed user prompt dialog: You need a browser which supports WebGL to run this content. Try installing Firefox.
[task 2023-11-21T04:25:35.826Z] 04:25:35    ERROR -  Traceback (most recent call last):
[task 2023-11-21T04:25:35.827Z] 04:25:35     INFO -    File "C:\Users\task_1700538604\build\tests\raptor\raptor\raptor.py", line 186, in <module>
[task 2023-11-21T04:25:35.827Z] 04:25:35     INFO -      main()
[task 2023-11-21T04:25:35.827Z] 04:25:35     INFO -    File "C:\Users\task_1700538604\build\tests\raptor\raptor\raptor.py", line 135, in main
[task 2023-11-21T04:25:35.828Z] 04:25:35     INFO -      success = raptor.run_tests(raptor_test_list, raptor_test_names)
[task 2023-11-21T04:25:35.828Z] 04:25:35     INFO -    File "C:\Users\task_1700538604\build\tests\raptor\raptor\perftest.py", line 479, in run_tests
[task 2023-11-21T04:25:35.828Z] 04:25:35     INFO -      self.run_test(test, timeout=int(test.get("page_timeout")))
[task 2023-11-21T04:25:35.829Z] 04:25:35     INFO -    File "C:\Users\task_1700538604\build\tests\raptor\raptor\browsertime\base.py", line 1005, in run_test
[task 2023-11-21T04:25:35.829Z] 04:25:35     INFO -      raise Exception(self.browsertime_failure)
[task 2023-11-21T04:25:35.830Z] 04:25:35     INFO -  Exception: Failed waiting on page http://127.0.0.1:49958/unity-webgl/index.html?raptor to finished loading, timed out after 120000 ms UnexpectedAlertOpenError: Dismissed user prompt dialog: You need a browser which supports WebGL to run this content. Try installing Firefox.
[task 2023-11-21T04:25:35.864Z] 04:25:35     INFO - Return code: 1
[task 2023-11-21T04:25:35.864Z] 04:25:35  WARNING - setting return code to 1
[task 2023-11-21T04:25:35.864Z] 04:25:35     INFO - Copying Raptor results to upload dir:
[task 2023-11-21T04:25:35.864Z] 04:25:35     INFO - C:\Users\task_1700538604\build\blobber_upload_dir\perfherder-data.json
[task 2023-11-21T04:25:35.864Z] 04:25:35     INFO - Copying raptor results from C:\Users\task_1700538604\build\raptor.json to C:\Users\task_1700538604\build\blobber_upload_dir\perfherder-data.json
[task 2023-11-21T04:25:35.865Z] 04:25:35 CRITICAL - Error copying results C:\Users\task_1700538604\build\raptor.json to upload dir C:\Users\task_1700538604\build\blobber_upload_dir\perfherder-data.json
[task 2023-11-21T04:25:35.865Z] 04:25:35     INFO - [Errno 2] No such file or directory: 'C:\\Users\\task_1700538604\\build\\raptor.json'
[task 2023-11-21T04:25:35.865Z] 04:25:35     INFO - Running post-action listener: _package_coverage_data
[task 2023-11-21T04:25:35.865Z] 04:25:35     INFO - Running post-action listener: _resource_record_post_action
[task 2023-11-21T04:25:35.865Z] 04:25:35     INFO - Running post-action listener: process_java_coverage_data
[task 2023-11-21T04:25:35.865Z] 04:25:35     INFO - Running post-action listener: stop_device
[task 2023-11-21T04:25:35.866Z] 04:25:35     INFO - [mozharness: 2023-11-21 04:25:35.865501Z] Finished run-tests step (success)
[task 2023-11-21T04:25:35.866Z] 04:25:35     INFO - Running post-run listener: _resource_record_post_run
[task 2023-11-21T04:25:35.980Z] 04:25:35     INFO - Total resource usage - Wall time: 75s; CPU: 6%; Read bytes: 40200704; Write bytes: 1404919808; Read time: 2; Write time: 8
[task 2023-11-21T04:25:35.980Z] 04:25:35     INFO - TinderboxPrint: CPU usage<br/>5.7%
[task 2023-11-21T04:25:35.980Z] 04:25:35     INFO - TinderboxPrint: I/O read bytes / time<br/>40,200,704 / 2
[task 2023-11-21T04:25:35.980Z] 04:25:35     INFO - TinderboxPrint: I/O write bytes / time<br/>1,404,919,808 / 8
[task 2023-11-21T04:25:35.980Z] 04:25:35     INFO - TinderboxPrint: CPU idle<br/>564.8 (94.2%)
[task 2023-11-21T04:25:35.980Z] 04:25:35     INFO - TinderboxPrint: CPU system<br/>15.9 (2.7%)
[task 2023-11-21T04:25:35.980Z] 04:25:35     INFO - TinderboxPrint: CPU user<br/>17.7 (2.9%)
[task 2023-11-21T04:25:35.980Z] 04:25:35     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-21T04:25:35.981Z] 04:25:35     INFO - install - Wall time: 2s; CPU: 17%; Read bytes: 551936; Write bytes: 17948672; Read time: 0; Write time: 0
[task 2023-11-21T04:25:35.986Z] 04:25:35     INFO - run-tests - Wall time: 73s; CPU: 5%; Read bytes: 39648768; Write bytes: 1386971136; Read time: 2; Write time: 8
[task 2023-11-21T04:25:36.196Z] 04:25:36  WARNING - returning nonzero exit status 1
[taskcluster 2023-11-21T04:25:36.238Z]    Exit Code: 1
[taskcluster 2023-11-21T04:25:36.238Z]    User Time: 0s
[taskcluster 2023-11-21T04:25:36.238Z]  Kernel Time: 31.25ms
[taskcluster 2023-11-21T04:25:36.238Z]    Wall Time: 4m30.0173797s
[taskcluster 2023-11-21T04:25:36.238Z]       Result: FAILED
[taskcluster 2023-11-21T04:25:36.238Z] === Task Finished ===
[taskcluster 2023-11-21T04:25:36.238Z] Task Duration: 4m30.0173797s
[taskcluster 2023-11-21T04:25:36.336Z] Uploading artifact public/logs/localconfig.json from file logs\localconfig.json with content encoding "gzip", mime type "application/octet-stream" and expiry 2024-11-20T01:53:54.018Z
[taskcluster 2023-11-21T04:25:36.731Z] Uploading artifact public/test_info/profile_resource-usage.json from file build\blobber_upload_dir\profile_resource-usage.json with content encoding "gzip", mime type "application/octet-stream" and expiry 2024-11-20T01:53:54.018Z
[taskcluster 2023-11-21T04:25:37.052Z] Uploading artifact public/test_info/resource-usage.json from file build\blobber_upload_dir\resource-usage.json with content encoding "gzip", mime type "application/octet-stream" and expiry 2024-11-20T01:53:54.018Z
[taskcluster 2023-11-21T04:25:37.406Z] Uploading redirect artifact public/logs/live.log to URL https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/YUywwG1oSjKJivhvAsbBHA/runs/0/artifacts/public/logs/live_backing.log with mime type "text/plain; charset=utf-8" and expiry 2024-11-20T01:53:54.018Z
[taskcluster:error] exit status 1

Comment 1

[Cosmin Sabou [:CosminS]]

Coming from Bug 1860062 after landing here.

Comment 2

[BugBot [:suhaib / :marco/ :calixte]]

Set release status flags based on info from the regressing bug 1860062

Comment 3

[Donal Meehan [:dmeehan]]

Setting Fx122 to fixed, the regressor was backed out of central

Comment 4

[Cosmin Sabou [:CosminS]]

Backed out of central in https://bugzilla.mozilla.org/show_bug.cgi?id=1860062#c10, will close this one.

Comment 5

[Intermittent Failures Robot]

4 failures in 3623 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 4

Platform and build breakdown:

• windows10-64-shippable-qr: 3
  • opt: 3
• linux1804-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1865770&startday=2023-11-20&endday=2023-11-26&tree=all