Skip to content

Instantly share code, notes, and snippets.

@stephendonner

stephendonner/gist:85439190f1329f1c2c64d7be5ea60312

Created December 5, 2019 18:26
Show Gist options

  • Select an option

    Learn more about clone URLs
  • Save stephendonner/85439190f1329f1c2c64d7be5ea60312 to your computer and use it in GitHub Desktop.

Select an option

Learn more about clone URLs
Save stephendonner/85439190f1329f1c2c64d7be5ea60312 to your computer and use it in GitHub Desktop.
Download ZIP
Raw
gistfile1.txt
stephendonner-7hlvdq:mozilla-unified sdonner$ moz-phab patch D55786
Patching revision: D55786
Checked out 3dc70a33491f
Bookmark set to D55786
D55786 applied
stephendonner-7hlvdq:mozilla-unified sdonner$ ./mach raptor -t raptor-tp6-1-cold --with-conditioned-profile --post-startup-delay 2 --browser-cycles 2
Updating external benchmarks from https://github.com/mozilla/perf-automation
Cloning the benchmarks to /Users/sdonner/.mozbuild/performance-tests
Switched to branch 'master'
Your branch is up to date with 'origin/master'.
Already up to date.
Note: switching to 'e19a0865c946ae2f9a64dd25614b1c275a3996b2'.
You are in 'detached HEAD' state. You can look around, make experimental
changes and commit them, and you can discard any commits you make in this
state without impacting any branches by switching back to a branch.
If you want to create a new branch to retain commits you create, you may
do so (now or later) by using -c with the switch command. Example:
git switch -c <new-branch-name>
Or undo this operation with:
git switch -
Turn off this advice by setting config variable advice.detachedHead to false
HEAD is now at e19a086 Merge pull request #20 from marianrai/Add_jetstream2_benchmark_suite
18:19:38 INFO - ConsoleLogger online at 20191205 18:19:38Z in /Users/sdonner/mozilla-source/mozilla-unified
18:19:38 INFO - Run as ./mach raptor -t raptor-tp6-1-cold --with-conditioned-profile --post-startup-delay 2 --browser-cycles 2
18:19:38 INFO - Dumping config to /Users/sdonner/mozilla-source/mozilla-unified/testing/mozharness/logs/localconfig.json.
18:19:38 INFO - {u'app': u'firefox',
18:19:38 INFO - 'append_to_log': False,
18:19:38 INFO - u'base_work_dir': u'/Users/sdonner/mozilla-source/mozilla-unified/testing/mozharness',
18:19:38 INFO - u'binary_path': u'/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/dist/Nightly.app/Contents/MacOS/firefox',
18:19:38 INFO - u'browsertime': False,
18:19:38 INFO - u'browsertime_browsertimejs': u'/Users/sdonner/mozilla-source/mozilla-unified/tools/browsertime/node_modules/browsertime/bin/browsertime.js',
18:19:38 INFO - u'browsertime_node': u'/Users/sdonner/.mozbuild/node/bin/node',
18:19:38 INFO - u'browsertime_video': False,
18:19:38 INFO - 'code_coverage': False,
18:19:38 INFO - u'cold': False,
18:19:38 INFO - 'config_files': (),
18:19:38 INFO - u'cpu_test': False,
18:19:38 INFO - u'debug_mode': False,
18:19:38 INFO - u'default_actions': (u'populate-webroot',
18:19:38 INFO - u'install-chromium-distribution',
18:19:38 INFO - u'create-virtualenv',
18:19:38 INFO - u'run-tests'),
18:19:38 INFO - 'disable_ccov_upload': False,
18:19:38 INFO - u'e10s': True,
18:19:38 INFO - u'enable_fission': False,
18:19:38 INFO - u'enable_webrender': False,
18:19:38 INFO - u'exes': {u'python': u'/usr/local/opt/python@2/bin/python2.7',
18:19:38 INFO - u'virtualenv': (u'/usr/local/opt/python@2/bin/python2.7',
18:19:38 INFO - u'/Users/sdonner/mozilla-source/mozilla-unified/third_party/python/virtualenv/virtualenv.py')},
18:19:38 INFO - u'extra_prefs': (),
18:19:38 INFO - 'find_links': ('https://pypi.pub.build.mozilla.org/pub',),
18:19:38 INFO - u'gecko_profile': False,
18:19:38 INFO - u'host': u'127.0.0.1',
18:19:38 INFO - u'is_release_build': False,
18:19:38 INFO - 'java_code_coverage': False,
18:19:38 INFO - 'log_level': 'info',
18:19:38 INFO - u'log_name': u'raptor',
18:19:38 INFO - 'log_to_console': True,
18:19:38 INFO - u'memory_test': False,
18:19:38 INFO - u'noinstall': False,
18:19:38 INFO - u'obj_path': u'/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0',
18:19:38 INFO - 'opt_config_files': (),
18:19:38 INFO - 'per_test_coverage': False,
18:19:38 INFO - 'pip_index': False,
18:19:38 INFO - u'power_test': False,
18:19:38 INFO - u'pypi_url': u'http://pypi.org/simple',
18:19:38 INFO - u'raptor_cmd_line_args': (u'-t',
18:19:38 INFO - u'raptor-tp6-1-cold',
18:19:38 INFO - u'--with-conditioned-profile',
18:19:38 INFO - u'--post-startup-delay',
18:19:38 INFO - u'2',
18:19:38 INFO - u'--browser-cycles',
18:19:38 INFO - u'2'),
18:19:38 INFO - u'raptor_path': u'/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor',
18:19:38 INFO - u'repo_path': u'/Users/sdonner/mozilla-source/mozilla-unified',
18:19:38 INFO - u'run_local': True,
18:19:38 INFO - u'title': u'stephendonner-7hlvdq',
18:19:38 INFO - 'verify': False,
18:19:38 INFO - u'virtualenv_path': u'/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/testing/raptor-venv',
18:19:38 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None},
18:19:38 INFO - u'with_conditioned_profile': False,
18:19:38 INFO - 'work_dir': 'build'}
18:19:38 INFO - [mozharness: 2019-12-05 18:19:38.863846Z] Skipping clobber step.
18:19:38 INFO - [mozharness: 2019-12-05 18:19:38.863889Z] Skipping download-and-extract step.
18:19:38 INFO - [mozharness: 2019-12-05 18:19:38.863928Z] Running populate-webroot step.
18:19:38 INFO - Running pre-action listener: _resource_record_pre_action
18:19:38 INFO - Running main action method: populate_webroot
18:19:38 INFO - Running post-action listener: _resource_record_post_action
18:19:38 INFO - [mozharness: 2019-12-05 18:19:38.864084Z] Finished populate-webroot step (success)
18:19:38 INFO - [mozharness: 2019-12-05 18:19:38.864123Z] Running install-chromium-distribution step.
18:19:38 INFO - Running pre-action listener: _resource_record_pre_action
18:19:38 INFO - Running main action method: install_chromium_distribution
18:19:38 INFO - Google Chrome or Chromium distributions are not required.
18:19:38 INFO - Running post-action listener: _resource_record_post_action
18:19:38 INFO - [mozharness: 2019-12-05 18:19:38.864305Z] Finished install-chromium-distribution step (success)
18:19:38 INFO - [mozharness: 2019-12-05 18:19:38.864344Z] Running create-virtualenv step.
18:19:38 INFO - Running pre-action listener: _resource_record_pre_action
18:19:38 INFO - Running main action method: create_virtualenv
18:19:38 INFO - Virtualenv already exists, skipping creation
18:19:38 INFO - Running post-action listener: _resource_record_post_action
18:19:38 INFO - Running post-action listener: _start_resource_monitoring
18:19:38 INFO - Starting resource monitoring.
18:19:38 INFO - [mozharness: 2019-12-05 18:19:38.888872Z] Finished create-virtualenv step (success)
18:19:38 INFO - [mozharness: 2019-12-05 18:19:38.889426Z] Skipping install step.
18:19:38 INFO - [mozharness: 2019-12-05 18:19:38.889515Z] Running run-tests step.
18:19:38 INFO - Running pre-action listener: _resource_record_pre_action
18:19:38 INFO - Running pre-action listener: _set_gcov_prefix
18:19:38 INFO - Running pre-action listener: timed_screenshots
18:19:38 INFO - Running main action method: run_tests
18:19:38 INFO - Running command: [u'/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/testing/raptor-venv/bin/python', u'--version']
18:19:38 INFO - Copy/paste: /Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/testing/raptor-venv/bin/python --version
18:19:38 INFO - Python 2.7.17
18:19:38 INFO - Return code: 0
18:19:38 INFO - ENV: MOZ_UPLOAD_DIR is now /Users/sdonner/mozilla-source/mozilla-unified/testing/mozharness/build/blobber_upload_dir
18:19:38 INFO - ENV: RUST_BACKTRACE is now full
18:19:38 INFO - ENV: MINIDUMP_SAVE_PATH is now /Users/sdonner/mozilla-source/mozilla-unified/testing/mozharness/build/blobber_upload_dir
18:19:38 INFO - Running command: [u'/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/testing/raptor-venv/bin/python', u'/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/raptor.py', u'--run-local', u'-t', u'raptor-tp6-1-cold', u'--with-conditioned-profile', u'--post-startup-delay', u'2', u'--browser-cycles', u'2', u'--browsertime-node', u'/Users/sdonner/.mozbuild/node/bin/node', u'--browsertime-browsertimejs', u'/Users/sdonner/mozilla-source/mozilla-unified/tools/browsertime/node_modules/browsertime/bin/browsertime.js', u'--host', u'127.0.0.1', u'--binary', u'/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/dist/Nightly.app/Contents/MacOS/firefox', u'--app', u'firefox', u'--obj-path', u'/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0', u'--log-tbpl-level=debug'] in /Users/sdonner/mozilla-source/mozilla-unified/testing/mozharness/build
18:19:38 INFO - Copy/paste: /Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/testing/raptor-venv/bin/python /Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/raptor.py --run-local -t raptor-tp6-1-cold --with-conditioned-profile --post-startup-delay 2 --browser-cycles 2 --browsertime-node /Users/sdonner/.mozbuild/node/bin/node --browsertime-browsertimejs /Users/sdonner/mozilla-source/mozilla-unified/tools/browsertime/node_modules/browsertime/bin/browsertime.js --host 127.0.0.1 --binary /Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/dist/Nightly.app/Contents/MacOS/firefox --app firefox --obj-path /Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0 --log-tbpl-level=debug
18:19:38 INFO - Using env: {u'EXTERNALTOOLSPATH': u'/Users/sdonner/mozilla-source/mozilla-unified/testing/mozharness/external_tools',
18:19:38 INFO - 'HOME': '/Users/sdonner',
18:19:38 INFO - u'JSGC_DISABLE_POISONING': u'1',
18:19:38 INFO - 'LANG': 'en_US.UTF-8',
18:19:38 INFO - 'LOGNAME': 'sdonner',
18:19:38 INFO - 'MACH_MAIN_PID': '12320',
18:19:38 INFO - 'MACH_STDOUT_ISATTY': '1',
18:19:38 INFO - u'MINIDUMP_SAVE_PATH': u'/Users/sdonner/mozilla-source/mozilla-unified/testing/mozharness/build/blobber_upload_dir',
18:19:38 INFO - u'MOZ_DEVELOPER_OBJ_DIR': u'/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0',
18:19:38 INFO - u'MOZ_DEVELOPER_REPO_DIR': u'/Users/sdonner/mozilla-source/mozilla-unified',
18:19:38 INFO - u'MOZ_UPLOAD_DIR': u'/Users/sdonner/mozilla-source/mozilla-unified/testing/mozharness/build/blobber_upload_dir',
18:19:38 INFO - 'PATH': u'/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/testing/raptor-venv/bin:/usr/local/sbin:/usr/local/bin:/usr/bin:/bin:/usr/sbin:/sbin:/Users/sdonner/geckodriver:/Applications/VMware Fusion.app/Contents/Public:/Applications/Wireshark.app/Contents/MacOS',
18:19:38 INFO - 'PWD': '/Users/sdonner/mozilla-source/mozilla-unified',
18:19:38 INFO - u'PYTHONPATH': u'/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor',
18:19:38 INFO - u'RUST_BACKTRACE': u'full',
18:19:38 INFO - u'SCRIPTSPATH': '/Users/sdonner/mozilla-source/mozilla-unified/testing/mozharness',
18:19:38 INFO - 'SHELL': '/bin/bash',
18:19:38 INFO - 'SHLVL': '1',
18:19:38 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.WcwhY4murv/Listeners',
18:19:38 INFO - 'TERM': 'xterm-256color',
18:19:38 INFO - 'TERM_PROGRAM': 'Apple_Terminal',
18:19:38 INFO - 'TERM_PROGRAM_VERSION': '433',
18:19:38 INFO - 'TERM_SESSION_ID': 'B2890482-8174-4879-8441-E46ED60DCE26',
18:19:38 INFO - 'TMPDIR': '/var/folders/tn/jmgsfg315sd73yn_dnrf66c80000gn/T/',
18:19:38 INFO - 'USER': 'sdonner',
18:19:38 INFO - 'XPC_FLAGS': '0x0',
18:19:38 INFO - 'XPC_SERVICE_NAME': '0',
18:19:38 INFO - '__CF_USER_TEXT_ENCODING': '0x1F5:0x0:0x0'}
18:19:38 INFO - Calling [u'/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/testing/raptor-venv/bin/python', u'/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/raptor.py', u'--run-local', u'-t', u'raptor-tp6-1-cold', u'--with-conditioned-profile', u'--post-startup-delay', u'2', u'--browser-cycles', u'2', u'--browsertime-node', u'/Users/sdonner/.mozbuild/node/bin/node', u'--browsertime-browsertimejs', u'/Users/sdonner/mozilla-source/mozilla-unified/tools/browsertime/node_modules/browsertime/bin/browsertime.js', u'--host', u'127.0.0.1', u'--binary', u'/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/dist/Nightly.app/Contents/MacOS/firefox', u'--app', u'firefox', u'--obj-path', u'/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0', u'--log-tbpl-level=debug'] with output_timeout 3600
18:19:39 INFO - raptor-main Info: raptor-start
18:19:39 INFO - raptor-main Info: received command line arguments: Namespace(activity=None, app='firefox', binary='/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/dist/Nightly.app/Contents/MacOS/firefox', browser_cycles=2, browsertime=False, browsertime_browsertimejs='/Users/sdonner/mozilla-source/mozilla-unified/tools/browsertime/node_modules/browsertime/bin/browsertime.js', browsertime_chromedriver=None, browsertime_ffmpeg=None, browsertime_geckodriver=None, browsertime_node='/Users/sdonner/.mozbuild/node/bin/node', browsertime_video=False, cold=False, cpu_test=False, debug_mode=False, e10s=True, enable_fission=False, enable_webrender=False, extra_prefs={}, gecko_profile=False, gecko_profile_entries=None, gecko_profile_interval=None, gecko_profile_threads=None, host='127.0.0.1', installerpath=None, intent=None, is_release_build=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='debug', log_unittest=None, log_xunit=None, memory_test=False, noinstall=False, obj_path='/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0', page_cycles=None, page_timeout=None, post_startup_delay=2, power_test=False, run_local=True, symbols_path=None, test='raptor-tp6-1-cold', test_url_params=None, with_conditioned_profile=True)
18:19:39 INFO - raptor-manifest Info: /Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/raptor.ini
18:19:39 INFO - raptor-manifest Info: configuring settings for test raptor-tp6-amazon-firefox-cold
18:19:39 INFO - raptor-manifest Info: setting browser-cycles to 2 as specified on cmd line
18:19:39 INFO - raptor-main Info: raptor tests scheduled to run:
18:19:39 INFO - raptor-main Info: raptor-tp6-amazon-firefox-cold
18:19:39 INFO - mozversion application_buildid: 20191203165542
18:19:39 INFO - mozversion application_changeset: 66f2dd3e084dab5cb9a6dc5a9941c0822bd6b37a
18:19:39 INFO - mozversion application_display_name: Nightly
18:19:39 INFO - mozversion application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384}
18:19:39 INFO - mozversion application_name: Firefox
18:19:39 INFO - mozversion application_remotingname: firefox
18:19:39 INFO - mozversion application_vendor: Mozilla
18:19:39 INFO - mozversion application_version: 73.0a1
18:19:39 INFO - mozversion platform_buildid: 20191203165542
18:19:39 INFO - mozversion platform_changeset: 66f2dd3e084dab5cb9a6dc5a9941c0822bd6b37a
18:19:39 INFO - mozversion platform_version: 73.0a1
18:19:39 INFO - raptor-main Info: Browser name: Firefox
18:19:39 INFO - raptor-main Info: Browser version: 73.0a1
18:19:39 INFO - mozversion application_buildid: 20191203165542
18:19:39 INFO - mozversion application_changeset: 66f2dd3e084dab5cb9a6dc5a9941c0822bd6b37a
18:19:39 INFO - mozversion application_display_name: Nightly
18:19:39 INFO - mozversion application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384}
18:19:39 INFO - mozversion application_name: Firefox
18:19:39 INFO - mozversion application_remotingname: firefox
18:19:39 INFO - mozversion application_vendor: Mozilla
18:19:39 INFO - mozversion application_version: 73.0a1
18:19:39 INFO - mozversion platform_buildid: 20191203165542
18:19:39 INFO - mozversion platform_changeset: 66f2dd3e084dab5cb9a6dc5a9941c0822bd6b37a
18:19:39 INFO - mozversion platform_version: 73.0a1
18:19:39 INFO - raptor-main Info: Browser name: Firefox
18:19:39 INFO - raptor-main Info: Browser version: 73.0a1
18:19:39 INFO - raptor-main Info: Using conditioned profile; setting post-startup-delay to: 0
18:19:39 INFO - raptor-main Info: main raptor init, config is: {'binary': '/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/dist/Nightly.app/Contents/MacOS/firefox', 'enable_fission': False, 'symbols_path': None, 'memory_test': False, 'cpu_test': False, 'enable_control_server_wait': False, 'e10s': True, 'app': 'firefox', 'gecko_profile_entries': None, 'power_test': False, 'run_local': True, 'platform': 'mac', 'host': '127.0.0.1', 'is_release_build': False, 'extra_prefs': {}, 'enable_webrender': False, 'with_conditioned_profile': True, 'gecko_profile_interval': None, 'processor': 'x86_64', 'gecko_profile': False, 'obj_path': '/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0'}
18:19:39 INFO - raptor-main Info: Making temp_download_dir from inside get_conditioned_profile /var/folders/tn/jmgsfg315sd73yn_dnrf66c80000gn/T/tmpCm5fMQ
18:19:45 INFO - Getting https://index.taskcluster.net/v1/task/gecko.v2.try.latest.firefox.condprof-macosx64/artifacts/public/condprof/profile-macosx64-cold-default.tgz
18:19:45 INFO - [2019-12-05T10:19:42.310018] Downloading https://index.taskcluster.net/v1/task/gecko.v2.try.latest.firefox.condprof-macosx64/artifacts/public/condprof/profile-macosx64-cold-default.tgz
18:19:45 INFO - Extracting the tarball content in /var/folders/tn/jmgsfg315sd73yn_dnrf66c80000gn/T/tmpCm5fMQ
18:19:45 INFO - Success, we have a profile to work with
18:19:45 INFO - raptor-main Info: temp_download_dir is: /var/folders/tn/jmgsfg315sd73yn_dnrf66c80000gn/T/tmpCm5fMQ
18:19:45 INFO - raptor-main Info: cond_prof_target_dir is: /var/folders/tn/jmgsfg315sd73yn_dnrf66c80000gn/T/tmpCm5fMQ
18:19:45 INFO - raptor-main Info: self.conditioned_profile_dir is now set: /var/folders/tn/jmgsfg315sd73yn_dnrf66c80000gn/T/tmpCm5fMQ
18:19:45 INFO - raptor-main Info: Merging profile: /Users/sdonner/mozilla-source/mozilla-unified/testing/profiles/base
18:19:45 INFO - raptor-main Info: Merging profile: /Users/sdonner/mozilla-source/mozilla-unified/testing/profiles/common
18:19:45 INFO - raptor-main Info: Merging profile: /Users/sdonner/mozilla-source/mozilla-unified/testing/profiles/perf
18:19:45 INFO - raptor-main Info: Merging profile: /Users/sdonner/mozilla-source/mozilla-unified/testing/profiles/raptor
18:19:45 INFO - raptor-main Info: Local browser profile: /var/folders/tn/jmgsfg315sd73yn_dnrf66c80000gn/T/tmpCm5fMQ
18:19:45 INFO - mozversion application_buildid: 20191203165542
18:19:45 INFO - mozversion application_changeset: 66f2dd3e084dab5cb9a6dc5a9941c0822bd6b37a
18:19:45 INFO - mozversion application_display_name: Nightly
18:19:45 INFO - mozversion application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384}
18:19:45 INFO - mozversion application_name: Firefox
18:19:45 INFO - mozversion application_remotingname: firefox
18:19:45 INFO - mozversion application_vendor: Mozilla
18:19:45 INFO - mozversion application_version: 73.0a1
18:19:45 INFO - mozversion platform_buildid: 20191203165542
18:19:45 INFO - mozversion platform_changeset: 66f2dd3e084dab5cb9a6dc5a9941c0822bd6b37a
18:19:45 INFO - mozversion platform_version: 73.0a1
18:19:45 INFO - raptor-main Info: Browser name: Firefox
18:19:45 INFO - raptor-main Info: Browser version: 73.0a1
18:19:46 INFO - raptor-control-server Info: raptor control server running on port 61057...
18:19:46 INFO - raptor-main Info: creating browser runner using mozrunner
18:19:46 INFO - raptor-main Info: test raptor-tp6-amazon-firefox-cold is running in cold mode; browser WILL be restarted between page cycles
18:19:46 INFO - raptor-main Info: begin browser cycle 1 of 2 for test raptor-tp6-amazon-firefox-cold
18:19:46 INFO - raptor-main Info: starting test: raptor-tp6-amazon-firefox-cold
18:19:46 INFO - raptor-main Info: starting raptor test: raptor-tp6-amazon-firefox-cold
18:19:46 INFO - raptor-main Info: test settings: {'expected_browser_cycles': 2, 'alert_threshold': '2.0', 'playback_pageset_manifest': 'mitm4-linux-firefox-amazon.manifest', 'browser_cycles': 2, 'here': '/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/tests/tp6/desktop', 'expected': 'pass', 'measure': ['fnbpaint', 'fcp', 'dcf', 'loadtime'], 'path': '/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/tests/tp6/desktop/raptor-tp6-amazon-firefox-cold', 'cold': True, 'manifest_relpath': 'tests/tp6/desktop/raptor-tp6-1-cold.ini', 'unit': 'ms', 'alert_on': ['fcp', 'loadtime'], 'name': 'raptor-tp6-amazon-firefox-cold', 'playback_recordings': 'amazon.mp', 'page_cycles': 1, 'apps': 'firefox', 'test_url': 'https://www.amazon.com/s?k=laptop&ref=nb_sb_noss_1', 'manifest': '/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/tests/tp6/desktop/raptor-tp6-1-cold.ini', 'ancestor_manifest': 'raptor.ini', 'page_timeout': '60000', 'playback': 'mitmproxy', 'browser_cycle': 1, 'lower_is_better': True, 'type': 'pageload', 'relpath': 'tests/tp6/desktop/raptor-tp6-amazon-firefox-cold'}
18:19:46 INFO - raptor-main Info: raptor config: {'subtest_alert_on': ['fcp', 'loadtime'], 'e10s': True, 'app': 'firefox', 'symbols_path': None, 'power_test': False, 'run_local': True, 'gecko_profile_interval': None, 'with_conditioned_profile': True, 'binary': '/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/dist/Nightly.app/Contents/MacOS/firefox', 'local_profile_dir': '/var/folders/tn/jmgsfg315sd73yn_dnrf66c80000gn/T/tmpCm5fMQ', 'enable_control_server_wait': False, 'platform': 'mac', 'enable_webrender': False, 'gecko_profile': False, 'gecko_profile_entries': None, 'host': '127.0.0.1', 'enable_fission': False, 'memory_test': False, 'extra_prefs': {}, 'obj_path': '/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0', 'cpu_test': False, 'is_release_build': False, 'processor': 'x86_64'}
18:19:46 INFO - raptor-gen-test-config Info: writing test settings into background js, so webext can get it
18:19:46 INFO - raptor-gen-test-config Info: finished writing test config to /Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/webext/raptor/auto_gen_test_config.js
18:19:46 INFO - raptor-main Info: installing webext /Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/../webext/raptor
18:19:46 INFO - raptor-main Info: test uses playback tool: mitmproxy
18:19:46 INFO - raptor-mitmproxy Info: mitmproxy was not provided with a 'playback_binary_manifest' Using default playback_binary_manifest
18:19:46 INFO - raptor-mitmproxy Info: mozproxy_dir used for mitmproxy downloads and exe files: /Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/testing/mozproxy
18:19:46 INFO - raptor-mitmproxy Info: mitmproxy binary already exists. Skipping download
18:19:46 INFO - raptor-mitmproxy Info: downloading mitmproxy pageset
18:19:46 INFO - raptor-mitmproxy Info: INFO - unzipping "mitm4-linux-firefox-amazon.zip"
18:19:46 INFO - raptor-mitmproxy Info: mitmdump path: /Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/testing/mozproxy/mitmdump-4.0.4/mitmdump
18:19:46 INFO - raptor-mitmproxy Info: browser path: /Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/dist/Nightly.app/Contents/MacOS/firefox
18:19:46 INFO - raptor-mitmproxy Info: Starting mitmproxy playback using env path: /Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/dist/Nightly.app/Contents/MacOS:/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/testing/raptor-venv/bin:/usr/local/sbin:/usr/local/bin:/usr/bin:/bin:/usr/sbin:/sbin:/Users/sdonner/geckodriver:/Applications/VMware Fusion.app/Contents/Public:/Applications/Wireshark.app/Contents/MacOS
18:19:46 INFO - raptor-mitmproxy Info: Starting mitmproxy playback using command: /Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/testing/mozproxy/mitmdump-4.0.4/mitmdump -v --set upstream_cert=false --set websocket=false --set server_replay_files=/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/testing/mozproxy/amazon.mp --scripts /Users/sdonner/mozilla-source/mozilla-unified/testing/mozbase/mozproxy/mozproxy/backends/mitm/scripts/alternate-server-replay-4.0.4.py
18:19:47 INFO - raptor-mitmproxy Info: Mitmproxy playback successfully started as pid 12373
18:19:47 INFO - raptor-mitmproxy Info: Installing mitmproxy CA certficate into Firefox
18:19:47 INFO - raptor-mitmproxy Info: folder already exists: /Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/dist/Nightly.app/Contents/Resources/distribution
18:19:47 INFO - raptor-mitmproxy Info: writing: /Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/dist/Nightly.app/Contents/Resources/distribution/policies.json
18:19:47 INFO - raptor-mitmproxy Info: reading: /Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/dist/Nightly.app/Contents/Resources/distribution/policies.json
18:19:47 INFO - raptor-mitmproxy Info: Firefox policies file contents:
18:19:47 INFO - raptor-mitmproxy Info: {
18:19:47 INFO - "policies": {
18:19:47 INFO - "Certificates": {
18:19:47 INFO - "Install": ["/Users/sdonner/.mitmproxy/mitmproxy-ca-cert.cer"]
18:19:47 INFO - },
18:19:47 INFO - "Proxy": {
18:19:47 INFO - "Mode": "manual",
18:19:47 INFO - "HTTPProxy": "127.0.0.1:8080",
18:19:47 INFO - "SSLProxy": "127.0.0.1:8080",
18:19:47 INFO - "Passthrough": "127.0.0.1",
18:19:47 INFO - "Locked": true
18:19:47 INFO - }
18:19:47 INFO - }
18:19:47 INFO - }
18:19:47 INFO - raptor-mitmproxy Info: Verified mitmproxy CA certificate is installed in Firefox
18:19:47 INFO - raptor-main Info: Playback recording information not available
18:19:47 INFO - raptor-main Info: starting firefox
18:19:47 INFO - Application command: /Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/dist/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/tn/jmgsfg315sd73yn_dnrf66c80000gn/T/tmpCm5fMQ
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] Attaching event listener successful!"
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] starting raptorRunner"
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] test name is: raptor-tp6-amazon-firefox-cold"
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] test settings url is: http://127.0.0.1:61057/json/raptor-tp6-amazon-firefox-cold.json"
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] raptor runner.js is loaded!"
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] posting to control server"
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] raptor runner.js is loaded!"
18:19:49 INFO - raptor-control-server Info: received webext_status: raptor runner.js is loaded!
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] testing on Firefox 73.0a1 20191203165542"
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] getting test settings from control server"
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] post success"
18:19:49 INFO - raptor-control-server Info: reading test settings from json/raptor-tp6-amazon-firefox-cold.json
18:19:49 INFO - raptor-control-server Info: sent test settings to webext runner
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] {\"raptor-options\": {\"expected_browser_cycles\": 2, \"subtest_unit\": \"ms\", \"alert_threshold\": 2.0, \"type\": \"pageload\", \"page_cycles\": 1, \"subtest_lower_is_better\": true, \"alert_on\": [\"fcp\", \"loadtime\"], \"test_url\": \"https://www.amazon.com/s?k=laptop&ref=nb_sb_noss_1\", \"page_timeout\": 60000, \"host\": \"127.0.0.1\", \"measure\": {\"fcp\": true, \"dcf\": true, \"fnbpaint\": true, \"loadtime\": true}, \"cold\": true, \"lower_is_better\": true, \"unit\": \"ms\"}}"
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] https://www.amazon.com/s?k=laptop&ref=nb_sb_noss_1"
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] using page timeout: 60000ms"
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] wrote settings to ext local storage"
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] pageload test start"
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] * pausing 0 seconds to let browser settle... *"
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] posting to control server"
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] * pausing 0 seconds to let browser settle... *"
18:19:49 INFO - raptor-control-server Info: received webext_status: * pausing 0 seconds to let browser settle... *
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] running 1 pagecycles of https://www.amazon.com/s?k=laptop&ref=nb_sb_noss_1"
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] posting to control server"
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] running 1 pagecycles of https://www.amazon.com/s?k=laptop&ref=nb_sb_noss_1"
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] post success"
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] opened new empty tab: 1"
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] posting to control server"
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] opened new empty tab: 1"
18:19:49 INFO - raptor-control-server Info: received webext_status: running 1 pagecycles of https://www.amazon.com/s?k=laptop&ref=nb_sb_noss_1
18:19:49 INFO - raptor-control-server Info: received webext_status: opened new empty tab: 1
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] post success"
18:19:49 INFO - PID 12377 | console.log: "[raptor-runnerjs] post success"
18:19:50 INFO - raptor-control-server Info: received webext_status: begin pagecycle 1
18:19:50 INFO - PID 12377 | console.log: "[raptor-runnerjs] begin pagecycle 1"
18:19:50 INFO - PID 12377 | console.log: "[raptor-runnerjs] posting to control server"
18:19:50 INFO - PID 12377 | console.log: "[raptor-runnerjs] begin pagecycle 1"
18:19:50 INFO - PID 12377 | console.log: "[raptor-runnerjs] post success"
18:19:51 INFO - raptor-control-server Info: received webext_status: update tab: 1
18:19:51 INFO - PID 12377 | console.log: "[raptor-runnerjs] update tab: 1"
18:19:51 INFO - PID 12377 | console.log: "[raptor-runnerjs] posting to control server"
18:19:51 INFO - PID 12377 | console.log: "[raptor-runnerjs] update tab: 1"
18:19:51 INFO - PID 12377 | console.log: "[raptor-runnerjs] test tab updated: 1"
18:19:51 INFO - PID 12377 | console.log: "[raptor-runnerjs] posting to control server"
18:19:51 INFO - PID 12377 | console.log: "[raptor-runnerjs] test tab updated: 1"
18:19:51 INFO - PID 12377 | console.log: "[raptor-runnerjs] post success"
18:19:51 INFO - raptor-control-server Info: received webext_status: test tab updated: 1
18:19:51 INFO - PID 12377 | console.log: "[raptor-runnerjs] post success"
18:19:53 INFO - PID 12377 | console.log: "[raptor-pageloadjs] pageloadjs raptorContentHandler!"
18:19:53 INFO - PID 12377 | console.log: "[raptor-pageloadjs] sending pageloadjs-ready message to runnerjs"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] received message from https://www.amazon.com/s?k=laptop&ref=nb_sb_noss_1"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] received pageloadjs-ready!"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] ready to poll for results; turning on page-timeout timer"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] now is 1575569993217, set raptor alarm raptor-page-timeout to expire at 1575570053217"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] checking results..."
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] setting timeout to checkForResult again in 250ms"
18:19:53 INFO - PID 12377 | console.log: "[raptor-pageloadjs] pageloadjs-ready-response"
18:19:53 INFO - PID 12377 | console.log: "[raptor-pageloadjs] will be measuring fnbpaint"
18:19:53 INFO - PID 12377 | console.log: "[raptor-pageloadjs] got fnbpaint"
18:19:53 INFO - PID 12377 | console.log: "[raptor-pageloadjs] sending result back to runner: fnbpaint 866"
18:19:53 INFO - PID 12377 | console.log: "[raptor-pageloadjs] will be measuring dcf"
18:19:53 INFO - PID 12377 | console.log: "[raptor-pageloadjs] got domContentFlushed: 1575569992923"
18:19:53 INFO - PID 12377 | console.log: "[raptor-pageloadjs] sending result back to runner: dcf 1260"
18:19:53 INFO - PID 12377 | console.log: "[raptor-pageloadjs] will be measuring first-contentful-paint"
18:19:53 INFO - PID 12377 | console.log: "[raptor-pageloadjs] got time to first-contentful-paint"
18:19:53 INFO - PID 12377 | console.log: "[raptor-pageloadjs] sending result back to runner: fcp 1140"
18:19:53 INFO - PID 12377 | console.log: "[raptor-pageloadjs] will be measuring loadtime"
18:19:53 INFO - PID 12377 | console.log: "[raptor-pageloadjs] got loadEventStart: 1575569993201"
18:19:53 INFO - PID 12377 | console.log: "[raptor-pageloadjs] sending result back to runner: loadtime 1538"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] received message from https://www.amazon.com/s?k=laptop&ref=nb_sb_noss_1"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] result: fnbpaint 866"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] received message from https://www.amazon.com/s?k=laptop&ref=nb_sb_noss_1"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] result: dcf 1260"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] received message from https://www.amazon.com/s?k=laptop&ref=nb_sb_noss_1"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] result: fcp 1140"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] received message from https://www.amazon.com/s?k=laptop&ref=nb_sb_noss_1"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] result: loadtime 1538"
18:19:53 INFO - PID 12377 | console.log: "[raptor-pageloadjs] confirmed fnbpaint"
18:19:53 INFO - PID 12377 | console.log: "[raptor-pageloadjs] confirmed dcf"
18:19:53 INFO - PID 12377 | console.log: "[raptor-pageloadjs] confirmed fcp"
18:19:53 INFO - PID 12377 | console.log: "[raptor-pageloadjs] confirmed loadtime"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] checking results..."
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] no more results pending; resolving checkForResult"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] results received"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] posting to control server"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] results received"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] Verifying results:"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] [object Object]"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] have 1 results for fnbpaint, as expected"
18:19:53 INFO - raptor-control-server Info: received webext_status: results received
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] have 1 results for dcf, as expected"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] have 1 results for fcp, as expected"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] have 1 results for loadtime, as expected"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] posting to control server"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] [object Object]"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] closed tab 1"
18:19:53 INFO - raptor-control-server Info: received webext_results: {u'expected_browser_cycles': 2, u'subtest_unit': u'ms', u'name': u'raptor-tp6-amazon-firefox-cold', u'lower_is_better': True, u'measurements': {u'dcf': [1260], u'fcp': [1140], u'fnbpaint': [866], u'loadtime': [1538]}, u'browser_cycle': u'1', u'subtest_lower_is_better': True, u'cold': True, u'browser': u'Firefox 73.0a1 20191203165542', u'type': u'pageload', u'page': u'https://www.amazon.com/s?k=laptop&ref=nb_sb_noss_1', u'unit': u'ms', u'alert_threshold': 2}
18:19:53 INFO - perftest-results-handler Info: received results in RaptorResultsHandler.add
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] pageload test finished"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] posting to control server"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] "
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] cancelled raptor alarm raptor-page-timeout"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] post success"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] post success"
18:19:53 INFO - raptor-control-server Info: received request to shutdown the browser
18:19:53 INFO - raptor-control-server Info: shutting down browser (pid: 12377)
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] post success"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] Removed tab: 1"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] posting to control server"
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] Removed tab: 1"
18:19:53 INFO - raptor-control-server Info: received webext_status: Removed tab: 1
18:19:53 INFO - PID 12377 | console.log: "[raptor-runnerjs] post success"
18:19:55 INFO - raptor-main Info: begin browser cycle 2 of 2 for test raptor-tp6-amazon-firefox-cold
18:19:55 INFO - raptor-main Info: starting test: raptor-tp6-amazon-firefox-cold
18:19:55 INFO - raptor-main Info: starting raptor test: raptor-tp6-amazon-firefox-cold
18:19:55 INFO - raptor-main Info: test settings: {'expected_browser_cycles': 2, 'alert_threshold': '2.0', 'playback_pageset_manifest': 'mitm4-linux-firefox-amazon.manifest', 'browser_cycles': 2, 'here': '/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/tests/tp6/desktop', 'expected': 'pass', 'measure': ['fnbpaint', 'fcp', 'dcf', 'loadtime'], 'path': '/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/tests/tp6/desktop/raptor-tp6-amazon-firefox-cold', 'cold': True, 'manifest_relpath': 'tests/tp6/desktop/raptor-tp6-1-cold.ini', 'unit': 'ms', 'alert_on': ['fcp', 'loadtime'], 'name': 'raptor-tp6-amazon-firefox-cold', 'playback_recordings': 'amazon.mp', 'page_cycles': 1, 'apps': 'firefox', 'test_url': 'https://www.amazon.com/s?k=laptop&ref=nb_sb_noss_1', 'manifest': '/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/tests/tp6/desktop/raptor-tp6-1-cold.ini', 'ancestor_manifest': 'raptor.ini', 'page_timeout': '60000', 'playback': 'mitmproxy', 'browser_cycle': 2, 'lower_is_better': True, 'type': 'pageload', 'relpath': 'tests/tp6/desktop/raptor-tp6-amazon-firefox-cold'}
18:19:55 INFO - raptor-main Info: raptor config: {'subtest_alert_on': ['fcp', 'loadtime'], 'e10s': True, 'app': 'firefox', 'symbols_path': None, 'power_test': False, 'playback_binary_zip': None, 'run_local': True, 'playback_files': ['/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/testing/mozproxy/amazon.mp'], 'gecko_profile_interval': None, 'with_conditioned_profile': True, 'binary': '/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/dist/Nightly.app/Contents/MacOS/firefox', 'local_profile_dir': '/var/folders/tn/jmgsfg315sd73yn_dnrf66c80000gn/T/tmpCm5fMQ', 'playback_binary_manifest': 'mitmproxy-rel-bin-4.0.4-{platform}.manifest', 'enable_control_server_wait': False, 'platform': 'mac', 'playback_version': '4.0.4', 'enable_webrender': False, 'gecko_profile': False, 'gecko_profile_entries': None, 'playback_pageset_manifest': '/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/playback/mitm4-linux-firefox-amazon.manifest', 'playback_pageset_zip': None, 'playback_tool': 'mitmproxy', 'host': '127.0.0.1', 'enable_fission': False, 'memory_test': False, 'extra_prefs': {}, 'obj_path': '/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0', 'cpu_test': False, 'is_release_build': False, 'processor': 'x86_64'}
18:19:55 INFO - raptor-gen-test-config Info: writing test settings into background js, so webext can get it
18:19:55 INFO - raptor-gen-test-config Info: finished writing test config to /Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/webext/raptor/auto_gen_test_config.js
18:19:55 INFO - raptor-main Info: installing webext /Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/../webext/raptor
18:19:55 INFO - raptor-main Info: Making temp_download_dir from inside get_conditioned_profile /var/folders/tn/jmgsfg315sd73yn_dnrf66c80000gn/T/tmpQJmbrE
18:20:00 INFO - Getting https://index.taskcluster.net/v1/task/gecko.v2.try.latest.firefox.condprof-macosx64/artifacts/public/condprof/profile-macosx64-cold-default.tgz
18:20:00 INFO - [2019-12-05T10:19:57.651185] Downloading https://index.taskcluster.net/v1/task/gecko.v2.try.latest.firefox.condprof-macosx64/artifacts/public/condprof/profile-macosx64-cold-default.tgz
18:20:00 INFO - Extracting the tarball content in /var/folders/tn/jmgsfg315sd73yn_dnrf66c80000gn/T/tmpQJmbrE
18:20:00 INFO - Success, we have a profile to work with
18:20:00 INFO - raptor-main Info: temp_download_dir is: /var/folders/tn/jmgsfg315sd73yn_dnrf66c80000gn/T/tmpQJmbrE
18:20:00 INFO - raptor-main Info: cond_prof_target_dir is: /var/folders/tn/jmgsfg315sd73yn_dnrf66c80000gn/T/tmpQJmbrE
18:20:00 INFO - raptor-main Info: self.conditioned_profile_dir is now set: /var/folders/tn/jmgsfg315sd73yn_dnrf66c80000gn/T/tmpQJmbrE
18:20:00 INFO - raptor-main Info: Merging profile: /Users/sdonner/mozilla-source/mozilla-unified/testing/profiles/base
18:20:00 INFO - raptor-main Info: Merging profile: /Users/sdonner/mozilla-source/mozilla-unified/testing/profiles/common
18:20:00 INFO - raptor-main Info: Merging profile: /Users/sdonner/mozilla-source/mozilla-unified/testing/profiles/perf
18:20:00 INFO - raptor-main Info: Merging profile: /Users/sdonner/mozilla-source/mozilla-unified/testing/profiles/raptor
18:20:00 INFO - raptor-main Info: Local browser profile: /var/folders/tn/jmgsfg315sd73yn_dnrf66c80000gn/T/tmpQJmbrE
18:20:00 INFO - raptor-main Info: starting test: raptor-tp6-amazon-firefox-cold
18:20:00 INFO - raptor-main Info: starting raptor test: raptor-tp6-amazon-firefox-cold
18:20:00 INFO - raptor-main Info: test settings: {'expected_browser_cycles': 2, 'alert_threshold': '2.0', 'playback_pageset_manifest': 'mitm4-linux-firefox-amazon.manifest', 'browser_cycles': 2, 'here': '/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/tests/tp6/desktop', 'expected': 'pass', 'measure': ['fnbpaint', 'fcp', 'dcf', 'loadtime'], 'path': '/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/tests/tp6/desktop/raptor-tp6-amazon-firefox-cold', 'cold': True, 'manifest_relpath': 'tests/tp6/desktop/raptor-tp6-1-cold.ini', 'unit': 'ms', 'alert_on': ['fcp', 'loadtime'], 'name': 'raptor-tp6-amazon-firefox-cold', 'playback_recordings': 'amazon.mp', 'page_cycles': 1, 'apps': 'firefox', 'test_url': 'https://www.amazon.com/s?k=laptop&ref=nb_sb_noss_1', 'manifest': '/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/tests/tp6/desktop/raptor-tp6-1-cold.ini', 'ancestor_manifest': 'raptor.ini', 'page_timeout': '60000', 'playback': 'mitmproxy', 'browser_cycle': 2, 'lower_is_better': True, 'type': 'pageload', 'relpath': 'tests/tp6/desktop/raptor-tp6-amazon-firefox-cold'}
18:20:00 INFO - raptor-main Info: raptor config: {'subtest_alert_on': ['fcp', 'loadtime'], 'e10s': True, 'app': 'firefox', 'symbols_path': None, 'power_test': False, 'playback_binary_zip': None, 'run_local': True, 'playback_files': ['/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/testing/mozproxy/amazon.mp'], 'gecko_profile_interval': None, 'with_conditioned_profile': True, 'binary': '/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/dist/Nightly.app/Contents/MacOS/firefox', 'local_profile_dir': '/var/folders/tn/jmgsfg315sd73yn_dnrf66c80000gn/T/tmpQJmbrE', 'playback_binary_manifest': 'mitmproxy-rel-bin-4.0.4-{platform}.manifest', 'enable_control_server_wait': False, 'platform': 'mac', 'playback_version': '4.0.4', 'enable_webrender': False, 'gecko_profile': False, 'gecko_profile_entries': None, 'playback_pageset_manifest': '/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/playback/mitm4-linux-firefox-amazon.manifest', 'playback_pageset_zip': None, 'playback_tool': 'mitmproxy', 'host': '127.0.0.1', 'enable_fission': False, 'memory_test': False, 'extra_prefs': {}, 'obj_path': '/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0', 'cpu_test': False, 'is_release_build': False, 'processor': 'x86_64'}
18:20:00 INFO - raptor-gen-test-config Info: writing test settings into background js, so webext can get it
18:20:00 INFO - raptor-gen-test-config Info: finished writing test config to /Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/webext/raptor/auto_gen_test_config.js
18:20:00 INFO - raptor-main Info: installing webext /Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/../webext/raptor
18:20:00 INFO - raptor-main Info: starting firefox
18:20:00 INFO - Application command: /Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/dist/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/tn/jmgsfg315sd73yn_dnrf66c80000gn/T/tmpQJmbrE
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] Attaching event listener successful!"
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] starting raptorRunner"
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] test name is: raptor-tp6-amazon-firefox-cold"
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] test settings url is: http://127.0.0.1:61057/json/raptor-tp6-amazon-firefox-cold.json"
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] raptor runner.js is loaded!"
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] posting to control server"
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] raptor runner.js is loaded!"
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] testing on Firefox 73.0a1 20191203165542"
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] getting test settings from control server"
18:20:02 INFO - raptor-control-server Info: received webext_status: raptor runner.js is loaded!
18:20:02 INFO - raptor-control-server Info: reading test settings from json/raptor-tp6-amazon-firefox-cold.json
18:20:02 INFO - raptor-control-server Info: sent test settings to webext runner
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] post success"
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] {\"raptor-options\": {\"expected_browser_cycles\": 2, \"subtest_unit\": \"ms\", \"alert_threshold\": 2.0, \"type\": \"pageload\", \"page_cycles\": 1, \"subtest_lower_is_better\": true, \"alert_on\": [\"fcp\", \"loadtime\"], \"test_url\": \"https://www.amazon.com/s?k=laptop&ref=nb_sb_noss_1\", \"page_timeout\": 60000, \"host\": \"127.0.0.1\", \"measure\": {\"fcp\": true, \"dcf\": true, \"fnbpaint\": true, \"loadtime\": true}, \"cold\": true, \"lower_is_better\": true, \"unit\": \"ms\"}}"
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] https://www.amazon.com/s?k=laptop&ref=nb_sb_noss_1"
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] using page timeout: 60000ms"
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] wrote settings to ext local storage"
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] pageload test start"
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] * pausing 0 seconds to let browser settle... *"
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] posting to control server"
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] * pausing 0 seconds to let browser settle... *"
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] running 1 pagecycles of https://www.amazon.com/s?k=laptop&ref=nb_sb_noss_1"
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] posting to control server"
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] running 1 pagecycles of https://www.amazon.com/s?k=laptop&ref=nb_sb_noss_1"
18:20:02 INFO - raptor-control-server Info: received webext_status: * pausing 0 seconds to let browser settle... *
18:20:02 INFO - raptor-control-server Info: received webext_status: running 1 pagecycles of https://www.amazon.com/s?k=laptop&ref=nb_sb_noss_1
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] post success"
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] opened new empty tab: 1"
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] posting to control server"
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] opened new empty tab: 1"
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] post success"
18:20:02 INFO - raptor-control-server Info: received webext_status: opened new empty tab: 1
18:20:02 INFO - PID 12385 | console.log: "[raptor-runnerjs] post success"
18:20:03 INFO - PID 12385 | console.log: "[raptor-runnerjs] begin pagecycle 1"
18:20:03 INFO - PID 12385 | console.log: "[raptor-runnerjs] posting to control server"
18:20:03 INFO - PID 12385 | console.log: "[raptor-runnerjs] begin pagecycle 1"
18:20:03 INFO - raptor-control-server Info: received webext_status: begin pagecycle 1
18:20:03 INFO - PID 12385 | console.log: "[raptor-runnerjs] post success"
18:20:04 INFO - PID 12385 | console.log: "[raptor-runnerjs] update tab: 1"
18:20:04 INFO - PID 12385 | console.log: "[raptor-runnerjs] posting to control server"
18:20:04 INFO - PID 12385 | console.log: "[raptor-runnerjs] update tab: 1"
18:20:04 INFO - raptor-control-server Info: received webext_status: update tab: 1
18:20:04 INFO - PID 12385 | console.log: "[raptor-runnerjs] test tab updated: 1"
18:20:04 INFO - PID 12385 | console.log: "[raptor-runnerjs] posting to control server"
18:20:04 INFO - PID 12385 | console.log: "[raptor-runnerjs] test tab updated: 1"
18:20:04 INFO - PID 12385 | console.log: "[raptor-runnerjs] post success"
18:20:04 INFO - raptor-control-server Info: received webext_status: test tab updated: 1
18:20:04 INFO - PID 12385 | console.log: "[raptor-runnerjs] post success"
18:20:06 INFO - PID 12385 | console.log: "[raptor-pageloadjs] pageloadjs raptorContentHandler!"
18:20:06 INFO - PID 12385 | console.log: "[raptor-pageloadjs] sending pageloadjs-ready message to runnerjs"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] received message from https://www.amazon.com/s?k=laptop&ref=nb_sb_noss_1"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] received pageloadjs-ready!"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] ready to poll for results; turning on page-timeout timer"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] now is 1575570006089, set raptor alarm raptor-page-timeout to expire at 1575570066089"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] checking results..."
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] setting timeout to checkForResult again in 250ms"
18:20:06 INFO - PID 12385 | console.log: "[raptor-pageloadjs] pageloadjs-ready-response"
18:20:06 INFO - PID 12385 | console.log: "[raptor-pageloadjs] will be measuring fnbpaint"
18:20:06 INFO - PID 12385 | console.log: "[raptor-pageloadjs] got fnbpaint"
18:20:06 INFO - PID 12385 | console.log: "[raptor-pageloadjs] sending result back to runner: fnbpaint 817"
18:20:06 INFO - PID 12385 | console.log: "[raptor-pageloadjs] will be measuring dcf"
18:20:06 INFO - PID 12385 | console.log: "[raptor-pageloadjs] got domContentFlushed: 1575570005851"
18:20:06 INFO - PID 12385 | console.log: "[raptor-pageloadjs] sending result back to runner: dcf 1109"
18:20:06 INFO - PID 12385 | console.log: "[raptor-pageloadjs] will be measuring first-contentful-paint"
18:20:06 INFO - PID 12385 | console.log: "[raptor-pageloadjs] got time to first-contentful-paint"
18:20:06 INFO - PID 12385 | console.log: "[raptor-pageloadjs] sending result back to runner: fcp 970"
18:20:06 INFO - PID 12385 | console.log: "[raptor-pageloadjs] will be measuring loadtime"
18:20:06 INFO - PID 12385 | console.log: "[raptor-pageloadjs] got loadEventStart: 1575570006072"
18:20:06 INFO - PID 12385 | console.log: "[raptor-pageloadjs] sending result back to runner: loadtime 1330"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] received message from https://www.amazon.com/s?k=laptop&ref=nb_sb_noss_1"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] result: fnbpaint 817"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] received message from https://www.amazon.com/s?k=laptop&ref=nb_sb_noss_1"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] result: dcf 1109"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] received message from https://www.amazon.com/s?k=laptop&ref=nb_sb_noss_1"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] result: fcp 970"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] received message from https://www.amazon.com/s?k=laptop&ref=nb_sb_noss_1"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] result: loadtime 1330"
18:20:06 INFO - PID 12385 | console.log: "[raptor-pageloadjs] confirmed fnbpaint"
18:20:06 INFO - PID 12385 | console.log: "[raptor-pageloadjs] confirmed dcf"
18:20:06 INFO - PID 12385 | console.log: "[raptor-pageloadjs] confirmed fcp"
18:20:06 INFO - PID 12385 | console.log: "[raptor-pageloadjs] confirmed loadtime"
18:20:06 INFO - raptor-control-server Info: received webext_status: results received
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] checking results..."
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] no more results pending; resolving checkForResult"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] results received"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] posting to control server"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] results received"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] Verifying results:"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] [object Object]"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] have 1 results for fnbpaint, as expected"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] have 1 results for dcf, as expected"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] have 1 results for fcp, as expected"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] have 1 results for loadtime, as expected"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] posting to control server"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] [object Object]"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] closed tab 1"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] pageload test finished"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] posting to control server"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] "
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] cancelled raptor alarm raptor-page-timeout"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] post success"
18:20:06 INFO - raptor-control-server Info: received webext_results: {u'expected_browser_cycles': 2, u'subtest_unit': u'ms', u'name': u'raptor-tp6-amazon-firefox-cold', u'lower_is_better': True, u'measurements': {u'dcf': [1109], u'fcp': [970], u'fnbpaint': [817], u'loadtime': [1330]}, u'browser_cycle': u'2', u'subtest_lower_is_better': True, u'cold': True, u'browser': u'Firefox 73.0a1 20191203165542', u'type': u'pageload', u'page': u'https://www.amazon.com/s?k=laptop&ref=nb_sb_noss_1', u'unit': u'ms', u'alert_threshold': 2}
18:20:06 INFO - perftest-results-handler Info: received results in RaptorResultsHandler.add
18:20:06 INFO - raptor-control-server Info: received request to shutdown the browser
18:20:06 INFO - raptor-control-server Info: shutting down browser (pid: 12385)
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] Removed tab: 1"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] posting to control server"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] Removed tab: 1"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] post success"
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] post success"
18:20:06 INFO - raptor-control-server Info: received webext_status: Removed tab: 1
18:20:06 INFO - PID 12385 | console.log: "[raptor-runnerjs] post success"
18:20:07 INFO - raptor-mitmproxy Info: Stopping mitmproxy playback, killing process 12373
18:20:07 INFO - raptor-mitmproxy Info: Successfully killed the mitmproxy playback process
18:20:07 INFO - raptor-mitmproxy Info: Turning off the browser proxy
18:20:07 INFO - raptor-mitmproxy Info: writing: /Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/dist/Nightly.app/Contents/Resources/distribution/policies.json
18:20:07 INFO - raptor-main Info: removing webext /Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/../webext/raptor
18:20:07 INFO - perftest-results-handler Info: summarizing raptor test results
18:20:07 INFO - perftest-output Info: turning on subtest alerting for measurement type: fcp
18:20:07 INFO - perftest-output Info: turning on subtest alerting for measurement type: loadtime
18:20:07 INFO - perftest-output Info: turning on subtest alerting for measurement type: fcp
18:20:07 INFO - perftest-output Info: turning on subtest alerting for measurement type: loadtime
18:20:07 INFO - perftest-output Info: combining results from browser cycle 1 for raptor-tp6-amazon-firefox-cold
18:20:07 INFO - perftest-output Info: created new combined result with intial cycle replicates
18:20:07 INFO - perftest-output Info: combining results from browser cycle 2 for raptor-tp6-amazon-firefox-cold
18:20:07 INFO - perftest-output Info: adding replicates for dcf
18:20:07 INFO - perftest-output Info: adding replicates for fcp
18:20:07 INFO - perftest-output Info: adding replicates for fnbpaint
18:20:07 INFO - perftest-output Info: adding replicates for loadtime
18:20:07 INFO - perftest-output Info: PERFHERDER_DATA: {"framework": {"name": "raptor"}, "application": {"version": "73.0a1", "name": "firefox"}, "suites": [{"extraOptions": ["condprof"], "name": "raptor-tp6-amazon-firefox-cold", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 1108.17, "subtests": [{"name": "dcf", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 1184.5, "replicates": [1260, 1109], "unit": "ms"}, {"name": "fcp", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 1055.0, "shouldAlert": true, "replicates": [1140, 970], "unit": "ms"}, {"name": "fnbpaint", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 841.5, "replicates": [866, 817], "unit": "ms"}, {"name": "loadtime", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 1434.0, "shouldAlert": true, "replicates": [1538, 1330], "unit": "ms"}], "type": "pageload", "unit": "ms"}]}
18:20:07 INFO - perftest-output Info: results can also be found locally at: /Users/sdonner/mozilla-source/mozilla-unified/testing/mozharness/build/raptor.json
18:20:07 INFO - perftest-results-handler Info: Validating PERFHERDER_DATA against /Users/sdonner/mozilla-source/mozilla-unified/testing/mozharness/external_tools/performance-artifact-schema.json
18:20:07 INFO - raptor-control-server Info: shutting down control server
18:20:07 INFO - raptor-main Info: finished
18:20:08 INFO - Return code: 0
18:20:08 INFO - Running post-action listener: _package_coverage_data
18:20:08 INFO - Running post-action listener: _resource_record_post_action
18:20:08 INFO - Running post-action listener: process_java_coverage_data
18:20:08 INFO - Running post-action listener: stop_device
18:20:08 INFO - [mozharness: 2019-12-05 18:20:08.013924Z] Finished run-tests step (success)
18:20:08 INFO - Running post-run listener: _resource_record_post_run
18:20:08 INFO - Total resource usage - Wall time: 29s; CPU: 11.0%; Read bytes: 385691648; Write bytes: 230432768; Read time: 10414; Write time: 985
18:20:08 INFO - TinderboxPrint: CPU usage<br/>11.2%
18:20:08 INFO - TinderboxPrint: I/O read bytes / time<br/>385,691,648 / 10,414
18:20:08 INFO - TinderboxPrint: I/O write bytes / time<br/>230,432,768 / 985
18:20:08 INFO - TinderboxPrint: CPU idle<br/>412.2 (88.8%)
18:20:08 INFO - TinderboxPrint: CPU system<br/>15.1 (3.3%)
18:20:08 INFO - TinderboxPrint: CPU user<br/>37.0 (8.0%)
18:20:08 INFO - TinderboxPrint: Swap in / out<br/>368,300,032 / 0
18:20:08 INFO - run-tests - Wall time: 29s; CPU: 11.0%; Read bytes: 385691648; Write bytes: 230432768; Read time: 10414; Write time: 985
stephendonner-7hlvdq:mozilla-unified sdonner$ atom testing/raptor/raptor/raptor.py
stephendonner-7hlvdq:mozilla-unified sdonner$ hg diff
diff --git a/testing/raptor/raptor/raptor.py b/testing/raptor/raptor/raptor.py
--- a/testing/raptor/raptor/raptor.py
+++ b/testing/raptor/raptor/raptor.py
@@ -190,7 +190,7 @@ either Raptor or browsertime."""
LOG.info("Making temp_download_dir from inside get_conditioned_profile {}"
.format(temp_download_dir))
platform = get_current_platform()
- cond_prof_target_dir = get_profile(temp_download_dir, platform, "cold")
+ cond_prof_target_dir = get_profile(temp_download_dir, platform, "settled")
LOG.info("temp_download_dir is: {}".format(temp_download_dir))
LOG.info("cond_prof_target_dir is: {}".format(cond_prof_target_dir))
stephendonner-7hlvdq:mozilla-unified sdonner$ ./mach raptor -t raptor-tp6-1-cold --with-conditioned-profile --post-startup-delay 2 --browser-cycles 2
Updating external benchmarks from https://github.com/mozilla/perf-automation
Cloning the benchmarks to /Users/sdonner/.mozbuild/performance-tests
Switched to branch 'master'
Your branch is up to date with 'origin/master'.
Already up to date.
Note: switching to 'e19a0865c946ae2f9a64dd25614b1c275a3996b2'.
You are in 'detached HEAD' state. You can look around, make experimental
changes and commit them, and you can discard any commits you make in this
state without impacting any branches by switching back to a branch.
If you want to create a new branch to retain commits you create, you may
do so (now or later) by using -c with the switch command. Example:
git switch -c <new-branch-name>
Or undo this operation with:
git switch -
Turn off this advice by setting config variable advice.detachedHead to false
HEAD is now at e19a086 Merge pull request #20 from marianrai/Add_jetstream2_benchmark_suite
18:20:38 INFO - ConsoleLogger online at 20191205 18:20:38Z in /Users/sdonner/mozilla-source/mozilla-unified
18:20:38 INFO - Run as ./mach raptor -t raptor-tp6-1-cold --with-conditioned-profile --post-startup-delay 2 --browser-cycles 2
18:20:38 INFO - Dumping config to /Users/sdonner/mozilla-source/mozilla-unified/testing/mozharness/logs/localconfig.json.
18:20:38 INFO - {u'app': u'firefox',
18:20:38 INFO - 'append_to_log': False,
18:20:38 INFO - u'base_work_dir': u'/Users/sdonner/mozilla-source/mozilla-unified/testing/mozharness',
18:20:38 INFO - u'binary_path': u'/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/dist/Nightly.app/Contents/MacOS/firefox',
18:20:38 INFO - u'browsertime': False,
18:20:38 INFO - u'browsertime_browsertimejs': u'/Users/sdonner/mozilla-source/mozilla-unified/tools/browsertime/node_modules/browsertime/bin/browsertime.js',
18:20:38 INFO - u'browsertime_node': u'/Users/sdonner/.mozbuild/node/bin/node',
18:20:38 INFO - u'browsertime_video': False,
18:20:38 INFO - 'code_coverage': False,
18:20:38 INFO - u'cold': False,
18:20:38 INFO - 'config_files': (),
18:20:38 INFO - u'cpu_test': False,
18:20:38 INFO - u'debug_mode': False,
18:20:38 INFO - u'default_actions': (u'populate-webroot',
18:20:38 INFO - u'install-chromium-distribution',
18:20:38 INFO - u'create-virtualenv',
18:20:38 INFO - u'run-tests'),
18:20:38 INFO - 'disable_ccov_upload': False,
18:20:38 INFO - u'e10s': True,
18:20:38 INFO - u'enable_fission': False,
18:20:38 INFO - u'enable_webrender': False,
18:20:38 INFO - u'exes': {u'python': u'/usr/local/opt/python@2/bin/python2.7',
18:20:38 INFO - u'virtualenv': (u'/usr/local/opt/python@2/bin/python2.7',
18:20:38 INFO - u'/Users/sdonner/mozilla-source/mozilla-unified/third_party/python/virtualenv/virtualenv.py')},
18:20:38 INFO - u'extra_prefs': (),
18:20:38 INFO - 'find_links': ('https://pypi.pub.build.mozilla.org/pub',),
18:20:38 INFO - u'gecko_profile': False,
18:20:38 INFO - u'host': u'127.0.0.1',
18:20:38 INFO - u'is_release_build': False,
18:20:38 INFO - 'java_code_coverage': False,
18:20:38 INFO - 'log_level': 'info',
18:20:38 INFO - u'log_name': u'raptor',
18:20:38 INFO - 'log_to_console': True,
18:20:38 INFO - u'memory_test': False,
18:20:38 INFO - u'noinstall': False,
18:20:38 INFO - u'obj_path': u'/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0',
18:20:38 INFO - 'opt_config_files': (),
18:20:38 INFO - 'per_test_coverage': False,
18:20:38 INFO - 'pip_index': False,
18:20:38 INFO - u'power_test': False,
18:20:38 INFO - u'pypi_url': u'http://pypi.org/simple',
18:20:38 INFO - u'raptor_cmd_line_args': (u'-t',
18:20:38 INFO - u'raptor-tp6-1-cold',
18:20:38 INFO - u'--with-conditioned-profile',
18:20:38 INFO - u'--post-startup-delay',
18:20:38 INFO - u'2',
18:20:38 INFO - u'--browser-cycles',
18:20:38 INFO - u'2'),
18:20:38 INFO - u'raptor_path': u'/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor',
18:20:38 INFO - u'repo_path': u'/Users/sdonner/mozilla-source/mozilla-unified',
18:20:38 INFO - u'run_local': True,
18:20:38 INFO - u'title': u'stephendonner-7hlvdq',
18:20:38 INFO - 'verify': False,
18:20:38 INFO - u'virtualenv_path': u'/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/testing/raptor-venv',
18:20:38 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None},
18:20:38 INFO - u'with_conditioned_profile': False,
18:20:38 INFO - 'work_dir': 'build'}
18:20:38 INFO - [mozharness: 2019-12-05 18:20:38.685171Z] Skipping clobber step.
18:20:38 INFO - [mozharness: 2019-12-05 18:20:38.685215Z] Skipping download-and-extract step.
18:20:38 INFO - [mozharness: 2019-12-05 18:20:38.685256Z] Running populate-webroot step.
18:20:38 INFO - Running pre-action listener: _resource_record_pre_action
18:20:38 INFO - Running main action method: populate_webroot
18:20:38 INFO - Running post-action listener: _resource_record_post_action
18:20:38 INFO - [mozharness: 2019-12-05 18:20:38.685414Z] Finished populate-webroot step (success)
18:20:38 INFO - [mozharness: 2019-12-05 18:20:38.685454Z] Running install-chromium-distribution step.
18:20:38 INFO - Running pre-action listener: _resource_record_pre_action
18:20:38 INFO - Running main action method: install_chromium_distribution
18:20:38 INFO - Google Chrome or Chromium distributions are not required.
18:20:38 INFO - Running post-action listener: _resource_record_post_action
18:20:38 INFO - [mozharness: 2019-12-05 18:20:38.685633Z] Finished install-chromium-distribution step (success)
18:20:38 INFO - [mozharness: 2019-12-05 18:20:38.685672Z] Running create-virtualenv step.
18:20:38 INFO - Running pre-action listener: _resource_record_pre_action
18:20:38 INFO - Running main action method: create_virtualenv
18:20:38 INFO - Virtualenv already exists, skipping creation
18:20:38 INFO - Running post-action listener: _resource_record_post_action
18:20:38 INFO - Running post-action listener: _start_resource_monitoring
18:20:38 INFO - Starting resource monitoring.
18:20:38 INFO - [mozharness: 2019-12-05 18:20:38.711149Z] Finished create-virtualenv step (success)
18:20:38 INFO - [mozharness: 2019-12-05 18:20:38.711726Z] Skipping install step.
18:20:38 INFO - [mozharness: 2019-12-05 18:20:38.711816Z] Running run-tests step.
18:20:38 INFO - Running pre-action listener: _resource_record_pre_action
18:20:38 INFO - Running pre-action listener: _set_gcov_prefix
18:20:38 INFO - Running pre-action listener: timed_screenshots
18:20:38 INFO - Running main action method: run_tests
18:20:38 INFO - Running command: [u'/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/testing/raptor-venv/bin/python', u'--version']
18:20:38 INFO - Copy/paste: /Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/testing/raptor-venv/bin/python --version
18:20:38 INFO - Python 2.7.17
18:20:38 INFO - Return code: 0
18:20:38 INFO - ENV: MOZ_UPLOAD_DIR is now /Users/sdonner/mozilla-source/mozilla-unified/testing/mozharness/build/blobber_upload_dir
18:20:38 INFO - ENV: RUST_BACKTRACE is now full
18:20:38 INFO - ENV: MINIDUMP_SAVE_PATH is now /Users/sdonner/mozilla-source/mozilla-unified/testing/mozharness/build/blobber_upload_dir
18:20:38 INFO - Running command: [u'/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/testing/raptor-venv/bin/python', u'/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/raptor.py', u'--run-local', u'-t', u'raptor-tp6-1-cold', u'--with-conditioned-profile', u'--post-startup-delay', u'2', u'--browser-cycles', u'2', u'--browsertime-node', u'/Users/sdonner/.mozbuild/node/bin/node', u'--browsertime-browsertimejs', u'/Users/sdonner/mozilla-source/mozilla-unified/tools/browsertime/node_modules/browsertime/bin/browsertime.js', u'--host', u'127.0.0.1', u'--binary', u'/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/dist/Nightly.app/Contents/MacOS/firefox', u'--app', u'firefox', u'--obj-path', u'/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0', u'--log-tbpl-level=debug'] in /Users/sdonner/mozilla-source/mozilla-unified/testing/mozharness/build
18:20:38 INFO - Copy/paste: /Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/testing/raptor-venv/bin/python /Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/raptor.py --run-local -t raptor-tp6-1-cold --with-conditioned-profile --post-startup-delay 2 --browser-cycles 2 --browsertime-node /Users/sdonner/.mozbuild/node/bin/node --browsertime-browsertimejs /Users/sdonner/mozilla-source/mozilla-unified/tools/browsertime/node_modules/browsertime/bin/browsertime.js --host 127.0.0.1 --binary /Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/dist/Nightly.app/Contents/MacOS/firefox --app firefox --obj-path /Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0 --log-tbpl-level=debug
18:20:38 INFO - Using env: {u'EXTERNALTOOLSPATH': u'/Users/sdonner/mozilla-source/mozilla-unified/testing/mozharness/external_tools',
18:20:38 INFO - 'HOME': '/Users/sdonner',
18:20:38 INFO - u'JSGC_DISABLE_POISONING': u'1',
18:20:38 INFO - 'LANG': 'en_US.UTF-8',
18:20:38 INFO - 'LOGNAME': 'sdonner',
18:20:38 INFO - 'MACH_MAIN_PID': '12493',
18:20:38 INFO - 'MACH_STDOUT_ISATTY': '1',
18:20:38 INFO - u'MINIDUMP_SAVE_PATH': u'/Users/sdonner/mozilla-source/mozilla-unified/testing/mozharness/build/blobber_upload_dir',
18:20:38 INFO - u'MOZ_DEVELOPER_OBJ_DIR': u'/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0',
18:20:38 INFO - u'MOZ_DEVELOPER_REPO_DIR': u'/Users/sdonner/mozilla-source/mozilla-unified',
18:20:38 INFO - u'MOZ_UPLOAD_DIR': u'/Users/sdonner/mozilla-source/mozilla-unified/testing/mozharness/build/blobber_upload_dir',
18:20:38 INFO - 'PATH': u'/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/testing/raptor-venv/bin:/usr/local/sbin:/usr/local/bin:/usr/bin:/bin:/usr/sbin:/sbin:/Users/sdonner/geckodriver:/Applications/VMware Fusion.app/Contents/Public:/Applications/Wireshark.app/Contents/MacOS',
18:20:38 INFO - 'PWD': '/Users/sdonner/mozilla-source/mozilla-unified',
18:20:38 INFO - u'PYTHONPATH': u'/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor',
18:20:38 INFO - u'RUST_BACKTRACE': u'full',
18:20:38 INFO - u'SCRIPTSPATH': '/Users/sdonner/mozilla-source/mozilla-unified/testing/mozharness',
18:20:38 INFO - 'SHELL': '/bin/bash',
18:20:38 INFO - 'SHLVL': '1',
18:20:38 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.WcwhY4murv/Listeners',
18:20:38 INFO - 'TERM': 'xterm-256color',
18:20:38 INFO - 'TERM_PROGRAM': 'Apple_Terminal',
18:20:38 INFO - 'TERM_PROGRAM_VERSION': '433',
18:20:38 INFO - 'TERM_SESSION_ID': 'B2890482-8174-4879-8441-E46ED60DCE26',
18:20:38 INFO - 'TMPDIR': '/var/folders/tn/jmgsfg315sd73yn_dnrf66c80000gn/T/',
18:20:38 INFO - 'USER': 'sdonner',
18:20:38 INFO - 'XPC_FLAGS': '0x0',
18:20:38 INFO - 'XPC_SERVICE_NAME': '0',
18:20:38 INFO - '__CF_USER_TEXT_ENCODING': '0x1F5:0x0:0x0'}
18:20:38 INFO - Calling [u'/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/testing/raptor-venv/bin/python', u'/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/raptor.py', u'--run-local', u'-t', u'raptor-tp6-1-cold', u'--with-conditioned-profile', u'--post-startup-delay', u'2', u'--browser-cycles', u'2', u'--browsertime-node', u'/Users/sdonner/.mozbuild/node/bin/node', u'--browsertime-browsertimejs', u'/Users/sdonner/mozilla-source/mozilla-unified/tools/browsertime/node_modules/browsertime/bin/browsertime.js', u'--host', u'127.0.0.1', u'--binary', u'/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/dist/Nightly.app/Contents/MacOS/firefox', u'--app', u'firefox', u'--obj-path', u'/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0', u'--log-tbpl-level=debug'] with output_timeout 3600
18:20:39 INFO - raptor-main Info: raptor-start
18:20:39 INFO - raptor-main Info: received command line arguments: Namespace(activity=None, app='firefox', binary='/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/dist/Nightly.app/Contents/MacOS/firefox', browser_cycles=2, browsertime=False, browsertime_browsertimejs='/Users/sdonner/mozilla-source/mozilla-unified/tools/browsertime/node_modules/browsertime/bin/browsertime.js', browsertime_chromedriver=None, browsertime_ffmpeg=None, browsertime_geckodriver=None, browsertime_node='/Users/sdonner/.mozbuild/node/bin/node', browsertime_video=False, cold=False, cpu_test=False, debug_mode=False, e10s=True, enable_fission=False, enable_webrender=False, extra_prefs={}, gecko_profile=False, gecko_profile_entries=None, gecko_profile_interval=None, gecko_profile_threads=None, host='127.0.0.1', installerpath=None, intent=None, is_release_build=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='debug', log_unittest=None, log_xunit=None, memory_test=False, noinstall=False, obj_path='/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0', page_cycles=None, page_timeout=None, post_startup_delay=2, power_test=False, run_local=True, symbols_path=None, test='raptor-tp6-1-cold', test_url_params=None, with_conditioned_profile=True)
18:20:39 INFO - raptor-manifest Info: /Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/raptor.ini
18:20:39 INFO - raptor-manifest Info: configuring settings for test raptor-tp6-amazon-firefox-cold
18:20:39 INFO - raptor-manifest Info: setting browser-cycles to 2 as specified on cmd line
18:20:39 INFO - raptor-main Info: raptor tests scheduled to run:
18:20:39 INFO - raptor-main Info: raptor-tp6-amazon-firefox-cold
18:20:39 INFO - mozversion application_buildid: 20191203165542
18:20:39 INFO - mozversion application_changeset: 66f2dd3e084dab5cb9a6dc5a9941c0822bd6b37a
18:20:39 INFO - mozversion application_display_name: Nightly
18:20:39 INFO - mozversion application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384}
18:20:39 INFO - mozversion application_name: Firefox
18:20:39 INFO - mozversion application_remotingname: firefox
18:20:39 INFO - mozversion application_vendor: Mozilla
18:20:39 INFO - mozversion application_version: 73.0a1
18:20:39 INFO - mozversion platform_buildid: 20191203165542
18:20:39 INFO - mozversion platform_changeset: 66f2dd3e084dab5cb9a6dc5a9941c0822bd6b37a
18:20:39 INFO - mozversion platform_version: 73.0a1
18:20:39 INFO - raptor-main Info: Browser name: Firefox
18:20:39 INFO - raptor-main Info: Browser version: 73.0a1
18:20:39 INFO - mozversion application_buildid: 20191203165542
18:20:39 INFO - mozversion application_changeset: 66f2dd3e084dab5cb9a6dc5a9941c0822bd6b37a
18:20:39 INFO - mozversion application_display_name: Nightly
18:20:39 INFO - mozversion application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384}
18:20:39 INFO - mozversion application_name: Firefox
18:20:39 INFO - mozversion application_remotingname: firefox
18:20:39 INFO - mozversion application_vendor: Mozilla
18:20:39 INFO - mozversion application_version: 73.0a1
18:20:39 INFO - mozversion platform_buildid: 20191203165542
18:20:39 INFO - mozversion platform_changeset: 66f2dd3e084dab5cb9a6dc5a9941c0822bd6b37a
18:20:39 INFO - mozversion platform_version: 73.0a1
18:20:39 INFO - raptor-main Info: Browser name: Firefox
18:20:39 INFO - raptor-main Info: Browser version: 73.0a1
18:20:39 INFO - raptor-main Info: Using conditioned profile; setting post-startup-delay to: 0
18:20:39 INFO - raptor-main Info: main raptor init, config is: {'binary': '/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/dist/Nightly.app/Contents/MacOS/firefox', 'enable_fission': False, 'symbols_path': None, 'memory_test': False, 'cpu_test': False, 'enable_control_server_wait': False, 'e10s': True, 'app': 'firefox', 'gecko_profile_entries': None, 'power_test': False, 'run_local': True, 'platform': 'mac', 'host': '127.0.0.1', 'is_release_build': False, 'extra_prefs': {}, 'enable_webrender': False, 'with_conditioned_profile': True, 'gecko_profile_interval': None, 'processor': 'x86_64', 'gecko_profile': False, 'obj_path': '/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0'}
18:20:39 INFO - raptor-main Info: Making temp_download_dir from inside get_conditioned_profile /var/folders/tn/jmgsfg315sd73yn_dnrf66c80000gn/T/tmpgwsujQ
18:20:40 INFO - Getting https://index.taskcluster.net/v1/task/gecko.v2.try.latest.firefox.condprof-macosx64/artifacts/public/condprof/profile-macosx64-settled-default.tgz
18:20:40 ERROR - Traceback (most recent call last):
18:20:40 INFO - File "/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/raptor.py", line 1846, in <module>
18:20:40 INFO - main()
18:20:40 INFO - File "/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/raptor.py", line 1801, in main
18:20:40 INFO - extra_prefs=args.extra_prefs or {}
18:20:40 INFO - File "/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/raptor.py", line 1059, in __init__
18:20:40 INFO - super(RaptorDesktop, self).__init__(*args, **kwargs)
18:20:40 INFO - File "/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/raptor.py", line 862, in __init__
18:20:40 INFO - super(Raptor, self).__init__(*args, **kwargs)
18:20:40 INFO - File "/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/raptor.py", line 182, in __init__
18:20:40 INFO - self.build_browser_profile()
18:20:40 INFO - File "/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/raptor.py", line 961, in build_browser_profile
18:20:40 INFO - super(Raptor, self).build_browser_profile()
18:20:40 INFO - File "/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/raptor.py", line 214, in build_browser_profile
18:20:40 INFO - self.get_conditioned_profile()
18:20:40 INFO - File "/Users/sdonner/mozilla-source/mozilla-unified/testing/raptor/raptor/raptor.py", line 193, in get_conditioned_profile
18:20:40 INFO - cond_prof_target_dir = get_profile(temp_download_dir, platform, "settled")
18:20:40 INFO - File "/Users/sdonner/mozilla-source/mozilla-unified/obj-x86_64-apple-darwin19.2.0/testing/raptor-venv/lib/python2.7/site-packages/condprof/client.py", line 59, in get_profile
18:20:40 INFO - raise ProfileNotFoundError(exists)
18:20:40 INFO - condprof.client.ProfileNotFoundError: 404
18:20:40 ERROR - Return code: 1
18:20:40 WARNING - setting return code to 1
18:20:40 INFO - Running post-action listener: _package_coverage_data
18:20:40 INFO - Running post-action listener: _resource_record_post_action
18:20:40 INFO - Running post-action listener: process_java_coverage_data
18:20:40 INFO - Running post-action listener: stop_device
18:20:40 INFO - [mozharness: 2019-12-05 18:20:40.118145Z] Finished run-tests step (success)
18:20:40 INFO - Running post-run listener: _resource_record_post_run
18:20:40 INFO - Total resource usage - Wall time: 1s; CPU: 4.0%; Read bytes: 0; Write bytes: 8192; Read time: 0; Write time: 1
18:20:40 INFO - TinderboxPrint: CPU usage<br/>4.5%
18:20:40 INFO - TinderboxPrint: I/O read bytes / time<br/>0 / 0
18:20:40 INFO - TinderboxPrint: I/O write bytes / time<br/>8,192 / 1
18:20:40 INFO - TinderboxPrint: CPU idle<br/>15.3 (95.5%)
18:20:40 INFO - TinderboxPrint: CPU system<br/>0.3 (1.8%)
18:20:40 INFO - TinderboxPrint: CPU user<br/>0.4 (2.7%)
18:20:40 INFO - TinderboxPrint: Swap in / out<br/>0 / 0
18:20:40 INFO - run-tests - Wall time: 1s; CPU: 4.0%; Read bytes: 0; Write bytes: 8192; Read time: 0; Write time: 1
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment