Closed Bug 1828417 Opened 1 year ago Closed 10 months ago

Intermittent raptor-browsertime Critical: [chrome] Exception [Errno 2] No such file or directory: '/var/folders/4h/686ck0gj45b85gqm7msj_jqr000014/T/tmpebx4zlad.mozrunner/Default/user.js' while removing mozprofile delimiters

Categories

(Testing :: Raptor, defect, P5)

defect

Tracking

(Not tracked)

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure)

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


[task 2023-04-17T11:55:33.681Z] 11:55:33     INFO - Calling ['/opt/worker/tasks/task_168173241785247/build/venv/bin/python', '/opt/worker/tasks/task_168173241785247/build/tests/raptor/raptor/raptor.py', '--browsertime-node', '/opt/worker/tasks/task_168173241785247/fetches/node/bin/node', '--browsertime-browsertimejs', '/opt/worker/tasks/task_168173241785247/fetches/browsertime/node_modules/browsertime/bin/browsertime.js', '--browsertime-chromedriver', '/opt/worker/tasks/task_168173241785247/fetches/{}chromedriver', '--browsertime-ffmpeg', '/opt/worker/tasks/task_168173241785247/fetches/ffmpeg-macos/ffmpeg', '--browsertime-geckodriver', '/opt/worker/tasks/task_168173241785247/fetches/geckodriver', '--browsertime', '--app', 'chrome', '--binary', '/Applications/Google Chrome.app/Contents/MacOS/Google Chrome', '--test', 'wasm-godot', '--symbolsPath', 'https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/f9oJHitJSBWwRzYmW0_q7A/artifacts/public/build/target.crashreporter-symbols.zip', '--conditioned-profile', 'settled', '--host', '127.0.0.1', '--log-tbpl-level=info'] with output_timeout 3600
[task 2023-04-17T11:55:34.198Z] 11:55:34     INFO -  Fission enabled through browser preferences
[task 2023-04-17T11:55:34.198Z] 11:55:34     INFO -  raptor-main Info: Python version: 3.7.9 (v3.7.9:13c94747c7, Aug 15 2020, 01:31:08)
[task 2023-04-17T11:55:34.199Z] 11:55:34     INFO -  [Clang 6.0 (clang-600.0.57)]
[task 2023-04-17T11:55:34.199Z] 11:55:34     INFO -  raptor-main Info: raptor-start
[task 2023-04-17T11:55:34.201Z] 11:55:34     INFO -  raptor-main Info: received command line arguments: Namespace(activity=None, app='chrome', binary='/Applications/Google Chrome.app/Contents/MacOS/Google Chrome', browser_cycles=None, browsertime=True, browsertime_browsertimejs='/opt/worker/tasks/task_168173241785247/fetches/browsertime/node_modules/browsertime/bin/browsertime.js', browsertime_chromedriver='/opt/worker/tasks/task_168173241785247/fetches/{}chromedriver', browsertime_existing_results=None, browsertime_ffmpeg='/opt/worker/tasks/task_168173241785247/fetches/ffmpeg-macos/ffmpeg', browsertime_geckodriver='/opt/worker/tasks/task_168173241785247/fetches/geckodriver', browsertime_no_ffwindowrecorder=False, browsertime_node='/opt/worker/tasks/task_168173241785247/fetches/node/bin/node', browsertime_user_args=[], browsertime_video=False, browsertime_vismet_script=None, browsertime_visualmetrics=False, chimera=False, clean=False, cold=False, collect_perfstats=False, conditioned_profile='settled', cpu_test=False, debug_mode=False, device_name=None, disable_perf_tuning=False, e10s=True, enable_marionette_trace=False, environment={}, extra_prefs={'fission.autostart': True}, extra_profiler_run=False, extra_summary_methods=[], fission=True, fission_mobile=False, gecko_profile=False, gecko_profile_entries=None, gecko_profile_extra_threads=[], gecko_profile_features=None, gecko_profile_interval=None, gecko_profile_threads=None, host='127.0.0.1', installerpath=None, intent=None, is_release_build=False, live_sites=False, log_errorsummary=None, log_grouped=None, log_html=None, log_mach=None, log_mach_buffer=None, log_mach_level=None, log_mach_screenshot=None, log_mach_verbose=None, log_raw=None, log_raw_level=None, log_tbpl=None, log_tbpl_buffer=None, log_tbpl_compact=None, log_tbpl_level='info', log_unittest=None, log_xunit=None, memory_test=False, mozbuild_path=None, noinstall=False, obj_path=None, page_cycles=None, page_timeout=None, post_startup_delay=30000, power_test=False, project='mozilla-central', run_local=False, symbols_path='https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/f9oJHitJSBWwRzYmW0_q7A/artifacts/public/build/target.crashreporter-symbols.zip', test='wasm-godot', test_bytecode_cache=False, test_url_params=None, verbose=False, webext=False)
[task 2023-04-17T11:55:34.201Z] 11:55:34     INFO -  raptor-manifest Info: /opt/worker/tasks/task_168173241785247/build/tests/raptor/raptor/raptor.ini
[task 2023-04-17T11:55:34.209Z] 11:55:34     INFO -  raptor-manifest Info: configuring settings for test wasm-godot
[task 2023-04-17T11:55:34.209Z] 11:55:34     INFO -  raptor-manifest Info: extra-profiler-run disabled
[task 2023-04-17T11:55:34.209Z] 11:55:34     INFO -  raptor-main Info: raptor tests scheduled to run:
[task 2023-04-17T11:55:34.209Z] 11:55:34     INFO -  raptor-main Info: wasm-godot
[task 2023-04-17T11:55:34.210Z] 11:55:34     INFO -  raptor-perftest Info: Using a conditioned profile.
[task 2023-04-17T11:55:34.212Z] 11:55:34     INFO -  raptor-perftest Warning: [chrome] Failed to get browser meta data through mozversion: LocalAppNotFoundError-Application not found at: /Applications/Google Chrome.app/Contents/MacOS
[task 2023-04-17T11:55:34.212Z] 11:55:34     INFO -  raptor-perftest Info: Attempting to get version through fallback method...
[task 2023-04-17T11:55:34.213Z] 11:55:34     INFO -  raptor-perftest Info: Browser name: chrome
[task 2023-04-17T11:55:34.214Z] 11:55:34     INFO -  raptor-perftest Info: Browser version: 98.0.4758.102
[task 2023-04-17T11:55:34.214Z] 11:55:34     INFO -  raptor-perftest Warning: [chrome] Failed to get browser meta data through mozversion: LocalAppNotFoundError-Application not found at: /Applications/Google Chrome.app/Contents/MacOS
[task 2023-04-17T11:55:34.214Z] 11:55:34     INFO -  raptor-perftest Info: Attempting to get version through fallback method...
[task 2023-04-17T11:55:34.215Z] 11:55:34     INFO -  raptor-perftest Info: Browser name: chrome
[task 2023-04-17T11:55:34.216Z] 11:55:34     INFO -  raptor-perftest Info: Browser version: 98.0.4758.102
[task 2023-04-17T11:55:34.216Z] 11:55:34     INFO -  raptor-perftest Info: Post startup delay set to 1000 ms
[task 2023-04-17T11:55:34.217Z] 11:55:34     INFO -  raptor-perftest Info: main raptor init, config is: {'app': 'chrome', 'binary': '/Applications/Google Chrome.app/Contents/MacOS/Google Chrome', 'platform': 'mac', 'processor': 'x86_64', 'run_local': False, 'obj_path': None, 'gecko_profile': False, 'gecko_profile_interval': None, 'gecko_profile_entries': None, 'gecko_profile_extra_threads': [], 'gecko_profile_threads': None, 'gecko_profile_features': None, 'extra_profiler_run': False, 'symbols_path': 'https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/f9oJHitJSBWwRzYmW0_q7A/artifacts/public/build/target.crashreporter-symbols.zip', 'host': '127.0.0.1', 'power_test': False, 'memory_test': False, 'cpu_test': False, 'cold': False, 'live_sites': False, 'is_release_build': False, 'enable_control_server_wait': False, 'e10s': True, 'device_name': None, 'fission': True, 'disable_perf_tuning': False, 'conditioned_profile': 'settled', 'test_bytecode_cache': False, 'chimera': False, 'extra_prefs': {'fission.autostart': True}, 'environment': {}, 'project': 'mozilla-central', 'verbose': False, 'extra_summary_methods': []}
[task 2023-04-17T11:55:34.217Z] 11:55:34     INFO -  raptor-perftest Info: Merging profile: /opt/worker/tasks/task_168173241785247/build/tests/raptor/raptor/profile_data/base
[task 2023-04-17T11:55:34.218Z] 11:55:34     INFO -  raptor-perftest Info: Merging profile: /opt/worker/tasks/task_168173241785247/build/tests/raptor/raptor/profile_data/common
[task 2023-04-17T11:55:34.218Z] 11:55:34     INFO -  raptor-perftest Info: Merging profile: /opt/worker/tasks/task_168173241785247/build/tests/raptor/raptor/profile_data/perf
[task 2023-04-17T11:55:34.218Z] 11:55:34     INFO -  raptor-perftest Info: Merging profile: /opt/worker/tasks/task_168173241785247/build/tests/raptor/raptor/profile_data/raptor
[task 2023-04-17T11:55:34.218Z] 11:55:34     INFO -  raptor-perftest Info: Browser preferences: {'fission.autostart': True}
[task 2023-04-17T11:55:34.219Z] 11:55:34     INFO -  raptor-perftest Info: Local browser profile: /var/folders/4h/686ck0gj45b85gqm7msj_jqr000014/T/tmpebx4zlad.mozrunner/Default
[task 2023-04-17T11:55:34.219Z] 11:55:34     INFO -  raptor-browsertime Info: Removing mozprofile delimiters from browser profile
[task 2023-04-17T11:55:34.219Z] 11:55:34 CRITICAL -  raptor-browsertime Critical: [chrome] Exception [Errno 2] No such file or directory: '/var/folders/4h/686ck0gj45b85gqm7msj_jqr000014/T/tmpebx4zlad.mozrunner/Default/user.js' while removing mozprofile delimiters
[task 2023-04-17T11:55:34.219Z] 11:55:34     INFO -  raptor-browsertime Info: cwd: '/opt/worker/tasks/task_168173241785247/build'
[task 2023-04-17T11:55:34.220Z] 11:55:34     INFO -  raptor-browsertime Info: browsertime_node: /opt/worker/tasks/task_168173241785247/fetches/node/bin/node
[task 2023-04-17T11:55:34.220Z] 11:55:34     INFO -  raptor-browsertime Info: browsertime_node: os.stat_result(st_mode=33261, st_ino=1938774897, st_dev=16777221, st_nlink=1, st_uid=36, st_gid=20, st_size=82563760, st_atime=1681732434, st_mtime=1670920349, st_ctime=1681732434)
[task 2023-04-17T11:55:34.220Z] 11:55:34     INFO -  raptor-browsertime Info: browsertime_browsertimejs: /opt/worker/tasks/task_168173241785247/fetches/browsertime/node_modules/browsertime/bin/browsertime.js
[task 2023-04-17T11:55:34.221Z] 11:55:34     INFO -  raptor-browsertime Info: browsertime_browsertimejs: os.stat_result(st_mode=33261, st_ino=1938779582, st_dev=16777221, st_nlink=1, st_uid=36, st_gid=20, st_size=6287, st_atime=1681732434, st_mtime=1677004066, st_ctime=1681732434)
[task 2023-04-17T11:55:34.221Z] 11:55:34     INFO -  raptor-browsertime Info: browsertime_geckodriver: /opt/worker/tasks/task_168173241785247/fetches/geckodriver
[task 2023-04-17T11:55:34.221Z] 11:55:34     INFO -  raptor-browsertime Info: browsertime_geckodriver: os.stat_result(st_mode=33261, st_ino=1938774882, st_dev=16777221, st_nlink=1, st_uid=36, st_gid=20, st_size=5419904, st_atime=1681732433, st_mtime=1681489312, st_ctime=1681732433)
[task 2023-04-17T11:55:34.222Z] 11:55:34     INFO -  raptor-browsertime Info: browsertime_chromedriver: /opt/worker/tasks/task_168173241785247/fetches/{}chromedriver
[task 2023-04-17T11:55:34.222Z] 11:55:34     INFO -  raptor-browsertime Info: browsertime_chromedriver: [Errno 2] No such file or directory: '/opt/worker/tasks/task_168173241785247/fetches/{}chromedriver'
[task 2023-04-17T11:55:34.222Z] 11:55:34     INFO -  raptor-browsertime Info: browsertime_user_args: []
[task 2023-04-17T11:55:34.222Z] 11:55:34     INFO -  raptor-browsertime Info: browsertime_user_args: stat: path should be string, bytes, os.PathLike or integer, not list
[task 2023-04-17T11:55:34.223Z] 11:55:34     INFO -  raptor-perftest Info: starting test: wasm-godot
[task 2023-04-17T11:55:34.223Z] 11:55:34     INFO -  raptor-benchmark Info: bench_dir: /opt/worker/tasks/task_168173241785247/build/tests/raptor/raptor/tests/webkit/PerformanceTests
[task 2023-04-17T11:55:34.223Z] 11:55:34     INFO -  raptor-benchmark Info: bench_dir contains:
[task 2023-04-17T11:55:34.224Z] 11:55:34     INFO -  raptor-benchmark Info: [PosixPath('/opt/worker/tasks/task_168173241785247/build/tests/raptor/raptor/tests/webkit/PerformanceTests/six-speed'), PosixPath('/opt/worker/tasks/task_168173241785247/build/tests/raptor/raptor/tests/webkit/PerformanceTests/SunSpider'), PosixPath('/opt/worker/tasks/task_168173241785247/build/tests/raptor/raptor/tests/webkit/PerformanceTests/ARES-6'), PosixPath('/opt/worker/tasks/task_168173241785247/build/tests/raptor/raptor/tests/webkit/PerformanceTests/Speedometer'), PosixPath('/opt/worker/tasks/task_168173241785247/build/tests/raptor/raptor/tests/webkit/PerformanceTests/resources'), PosixPath('/opt/worker/tasks/task_168173241785247/build/tests/raptor/raptor/tests/webkit/PerformanceTests/StyleBench'), PosixPath('/opt/worker/tasks/task_168173241785247/build/tests/raptor/raptor/tests/webkit/PerformanceTests/MotionMark'), PosixPath('/opt/worker/tasks/task_168173241785247/build/tests/raptor/raptor/tests/webkit/PerformanceTests/wasm-godot'), PosixPath('/opt/worker/tasks/task_168173241785247/build/tests/raptor/raptor/tests/webkit/PerformanceTests/webaudio')]
[task 2023-04-17T11:55:34.224Z] 11:55:34     INFO -  raptor-benchmark Info: writing wptserve headers file
[task 2023-04-17T11:55:34.225Z] 11:55:34     INFO -  raptor-benchmark Info: wrote wpt headers file: /opt/worker/tasks/task_168173241785247/build/tests/raptor/raptor/tests/webkit/PerformanceTests/__dir__.headers
[task 2023-04-17T11:55:34.225Z] 11:55:34     INFO -  raptor-benchmark Info: starting webserver on '127.0.0.1:49268'
[task 2023-04-17T11:55:34.225Z] 11:55:34     INFO -  raptor-benchmark Info: serving benchmarks from here: /opt/worker/tasks/task_168173241785247/build/tests/raptor/raptor/tests/webkit/PerformanceTests
[task 2023-04-17T11:55:34.225Z] 11:55:34    ERROR -  Traceback (most recent call last):
[task 2023-04-17T11:55:34.226Z] 11:55:34     INFO -    File "/opt/worker/tasks/task_168173241785247/build/tests/raptor/raptor/raptor.py", line 204, in <module>
[task 2023-04-17T11:55:34.226Z] 11:55:34     INFO -      main()
[task 2023-04-17T11:55:34.226Z] 11:55:34     INFO -    File "/opt/worker/tasks/task_168173241785247/build/tests/raptor/raptor/raptor.py", line 150, in main
[task 2023-04-17T11:55:34.226Z] 11:55:34     INFO -      success = raptor.run_tests(raptor_test_list, raptor_test_names)
[task 2023-04-17T11:55:34.227Z] 11:55:34     INFO -    File "/opt/worker/tasks/task_168173241785247/build/tests/raptor/raptor/perftest.py", line 472, in run_tests
[task 2023-04-17T11:55:34.227Z] 11:55:34     INFO -      self.run_test(test, timeout=int(test.get("page_timeout")))
[task 2023-04-17T11:55:34.227Z] 11:55:34     INFO -    File "/opt/worker/tasks/task_168173241785247/build/tests/raptor/raptor/browsertime/base.py", line 687, in run_test
[task 2023-04-17T11:55:34.227Z] 11:55:34     INFO -      self.run_test_setup(test)
[task 2023-04-17T11:55:34.228Z] 11:55:34     INFO -    File "/opt/worker/tasks/task_168173241785247/build/tests/raptor/raptor/browsertime/base.py", line 157, in run_test_setup
[task 2023-04-17T11:55:34.228Z] 11:55:34     INFO -      "being tested: %s" % self.browsertime_chromedriver
[task 2023-04-17T11:55:34.228Z] 11:55:34     INFO -  Exception: Cannot find the chromedriver for the chrome version being tested: /opt/worker/tasks/task_168173241785247/fetches/98chromedriver
[task 2023-04-17T11:55:34.324Z] 11:55:34     INFO - Return code: 1
[task 2023-04-17T11:55:34.324Z] 11:55:34  WARNING - setting return code to 1
[task 2023-04-17T11:55:34.324Z] 11:55:34     INFO - Copying Raptor results to upload dir:
[task 2023-04-17T11:55:34.324Z] 11:55:34     INFO - /opt/worker/tasks/task_168173241785247/build/blobber_upload_dir/perfherder-data.json
[task 2023-04-17T11:55:34.324Z] 11:55:34     INFO - Copying raptor results from /opt/worker/tasks/task_168173241785247/build/raptor.json to /opt/worker/tasks/task_168173241785247/build/blobber_upload_dir/perfherder-data.json
[task 2023-04-17T11:55:34.324Z] 11:55:34 CRITICAL - Error copying results /opt/worker/tasks/task_168173241785247/build/raptor.json to upload dir /opt/worker/tasks/task_168173241785247/build/blobber_upload_dir/perfherder-data.json
[task 2023-04-17T11:55:34.324Z] 11:55:34     INFO - [Errno 2] No such file or directory: '/opt/worker/tasks/task_168173241785247/build/raptor.json'
[task 2023-04-17T11:55:34.325Z] 11:55:34     INFO - Running post-action listener: _package_coverage_data
[task 2023-04-17T11:55:34.325Z] 11:55:34     INFO - Running post-action listener: _resource_record_post_action
[task 2023-04-17T11:55:34.325Z] 11:55:34     INFO - Running post-action listener: process_java_coverage_data
[task 2023-04-17T11:55:34.325Z] 11:55:34     INFO - Running post-action listener: stop_device
[task 2023-04-17T11:55:34.326Z] 11:55:34     INFO - [mozharness: 2023-04-17 11:55:34.325926Z] Finished run-tests step (success)
[task 2023-04-17T11:55:34.326Z] 11:55:34     INFO - Running post-run listener: _resource_record_post_run
[task 2023-04-17T11:55:34.383Z] 11:55:34     INFO - Total resource usage - Wall time: 34s; CPU: 14%; Read bytes: 460080640; Write bytes: 455192576; Read time: 30809; Write time: 757
[task 2023-04-17T11:55:34.383Z] 11:55:34     INFO - TinderboxPrint: CPU usage<br/>13.7%
[task 2023-04-17T11:55:34.383Z] 11:55:34     INFO - TinderboxPrint: I/O read bytes / time<br/>460,080,640 / 30,809
[task 2023-04-17T11:55:34.383Z] 11:55:34     INFO - TinderboxPrint: I/O write bytes / time<br/>455,192,576 / 757
[task 2023-04-17T11:55:34.383Z] 11:55:34     INFO - TinderboxPrint: CPU idle<br/>348.8 (86.3%)
[task 2023-04-17T11:55:34.383Z] 11:55:34     INFO - TinderboxPrint: CPU system<br/>4.9 (1.2%)
[task 2023-04-17T11:55:34.383Z] 11:55:34     INFO - TinderboxPrint: CPU user<br/>50.3 (12.5%)
[task 2023-04-17T11:55:34.383Z] 11:55:34     INFO - TinderboxPrint: Swap in / out<br/>462,716,928 / 0
[task 2023-04-17T11:55:34.383Z] 11:55:34     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-04-17T11:55:34.384Z] 11:55:34     INFO - install - Wall time: 34s; CPU: 14%; Read bytes: 460080640; Write bytes: 455192576; Read time: 30809; Write time: 757
[task 2023-04-17T11:55:34.384Z] 11:55:34     INFO - run-tests - Wall time: 1s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2023-04-17T11:55:34.394Z] 11:55:34  WARNING - returning nonzero exit status 1
[taskcluster 2023-04-17T11:55:34.420Z]    Exit Code: 1
[taskcluster 2023-04-17T11:55:34.420Z]    User Time: 1m9.610183s
[taskcluster 2023-04-17T11:55:34.420Z]  Kernel Time: 14.288733s
[taskcluster 2023-04-17T11:55:34.420Z]    Wall Time: 1m41.888819s
[taskcluster 2023-04-17T11:55:34.420Z]       Result: FAILED
[taskcluster 2023-04-17T11:55:34.420Z] === Task Finished ===
[taskcluster 2023-04-17T11:55:34.420Z] Task Duration: 1m41.891375s
[taskcluster 2023-04-17T11:55:34.522Z] Uploading artifact public/logs/localconfig.json from file logs/localconfig.json with content encoding "gzip", mime type "application/json" and expiry 2023-07-16T10:32:31.569Z
[taskcluster 2023-04-17T11:55:34.734Z] 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-07-16T10:32:31.569Z
[taskcluster 2023-04-17T11:55:34.876Z] Uploading redirect artifact public/logs/live.log to URL https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/VzImrunaSbKa-hpJdeZFxg/runs/0/artifacts/public%2Flogs%2Flive_backing.log with mime type "text/plain; charset=utf-8" and expiry 2023-07-16T10:32:31.569Z
[taskcluster:error] exit status 1

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