builder: fx-team_yosemite_r7_test-g4-e10s slave: t-yosemite-r7-0085 starttime: 1468235101.23 results: success (0) buildid: 20160711012926 builduid: 4d62b50923894a60ad72f8fe9b9a3f05 revision: 76d556ef9180969ee8d690ed069732faded934a2 ========= Started set props: master (results: 0, elapsed: 0 secs) (at 2016-07-11 04:05:01.233439) ========= master: http://buildbot-master133.bb.releng.scl3.mozilla.com:8201/ ========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2016-07-11 04:05:01.233897) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2016-07-11 04:05:01.234174) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2016-07-11 04:05:01.315235) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2016-07-11 04:05:01.315604) ========= bash -c 'wget -Oarchiver_client.py --no-check-certificate --tries=10 --waitretry=3 https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py' in dir /builds/slave/test/. (timeout 1200 secs) watching logfiles {} argv: ['bash', '-c', 'wget -Oarchiver_client.py --no-check-certificate --tries=10 --waitretry=3 https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py'] environment: Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.60BmflXbZZ/Render GIT_SHARE_BASE_DIR=/builds/git-shared HG_SHARE_BASE_DIR=/builds/hg-shared HOME=/Users/cltbld IDLEIZER_DISABLE_SHUTDOWN=true LOGNAME=cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NO_EM_RESTART=1 PAGER=/bin/cat PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11 PWD=/builds/slave/test RUNNER_CONFIG_CMD=/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg SHELL=/bin/bash SSH_AUTH_SOCK=/private/tmp/com.apple.launchd.MN4hGYEesj/Listeners TMPDIR=/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/ TWISTD_LOG_PATH=/builds/slave/twistd.log USER=cltbld VERSIONER_PYTHON_PREFER_32_BIT=no VERSIONER_PYTHON_VERSION=2.7 XPCOM_DEBUG_BREAK=warn XPC_FLAGS=0x0 XPC_SERVICE_NAME=0 __CF_USER_TEXT_ENCODING=0x1C:0:0 using PTY: False --2016-07-11 04:05:01-- https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py Resolving hg.mozilla.org... 63.245.215.102, 63.245.215.25 Connecting to hg.mozilla.org|63.245.215.102|:443... connected. HTTP request sent, awaiting response... 200 Script output follows Length: 12141 (12K) [text/x-python] Saving to: 'archiver_client.py' 0K .......... . 100% 10.9M=0.001s 2016-07-11 04:05:01 (10.9 MB/s) - 'archiver_client.py' saved [12141/12141] program finished with exit code 0 elapsedTime=0.105582 ========= master_lag: 0.02 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2016-07-11 04:05:01.445147) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2016-07-11 04:05:01.445575) ========= rm -rf scripts properties in dir /builds/slave/test/. (timeout 1200 secs) watching logfiles {} argv: ['rm', '-rf', 'scripts', 'properties'] environment: Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.60BmflXbZZ/Render GIT_SHARE_BASE_DIR=/builds/git-shared HG_SHARE_BASE_DIR=/builds/hg-shared HOME=/Users/cltbld IDLEIZER_DISABLE_SHUTDOWN=true LOGNAME=cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NO_EM_RESTART=1 PAGER=/bin/cat PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11 PWD=/builds/slave/test RUNNER_CONFIG_CMD=/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg SHELL=/bin/bash SSH_AUTH_SOCK=/private/tmp/com.apple.launchd.MN4hGYEesj/Listeners TMPDIR=/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/ TWISTD_LOG_PATH=/builds/slave/twistd.log USER=cltbld VERSIONER_PYTHON_PREFER_32_BIT=no VERSIONER_PYTHON_VERSION=2.7 XPCOM_DEBUG_BREAK=warn XPC_FLAGS=0x0 XPC_SERVICE_NAME=0 __CF_USER_TEXT_ENCODING=0x1C:0:0 using PTY: False program finished with exit code 0 elapsedTime=0.027795 ========= master_lag: 0.02 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2016-07-11 04:05:01.495156) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 1 secs) (at 2016-07-11 04:05:01.495519) ========= bash -c 'python archiver_client.py mozharness --repo integration/fx-team --rev 76d556ef9180969ee8d690ed069732faded934a2 --destination scripts --debug' in dir /builds/slave/test/. (timeout 1200 secs) watching logfiles {} argv: ['bash', '-c', u'python archiver_client.py mozharness --repo integration/fx-team --rev 76d556ef9180969ee8d690ed069732faded934a2 --destination scripts --debug'] environment: Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.60BmflXbZZ/Render GIT_SHARE_BASE_DIR=/builds/git-shared HG_SHARE_BASE_DIR=/builds/hg-shared HOME=/Users/cltbld IDLEIZER_DISABLE_SHUTDOWN=true LOGNAME=cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NO_EM_RESTART=1 PAGER=/bin/cat PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11 PWD=/builds/slave/test RUNNER_CONFIG_CMD=/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg SHELL=/bin/bash SSH_AUTH_SOCK=/private/tmp/com.apple.launchd.MN4hGYEesj/Listeners TMPDIR=/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/ TWISTD_LOG_PATH=/builds/slave/twistd.log USER=cltbld VERSIONER_PYTHON_PREFER_32_BIT=no VERSIONER_PYTHON_VERSION=2.7 XPCOM_DEBUG_BREAK=warn XPC_FLAGS=0x0 XPC_SERVICE_NAME=0 __CF_USER_TEXT_ENCODING=0x1C:0:0 using PTY: False 2016-07-11 04:05:01,570 truncating revision to first 12 chars 2016-07-11 04:05:01,570 Setting DEBUG logging. 2016-07-11 04:05:01,570 attempt 1/10 2016-07-11 04:05:01,571 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/integration/fx-team/76d556ef9180?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness 2016-07-11 04:05:02,661 unpacking tar archive at: fx-team-76d556ef9180/testing/mozharness/ program finished with exit code 0 elapsedTime=1.342943 ========= master_lag: 0.02 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 1 secs) (at 2016-07-11 04:05:02.859856) ========= ========= Started set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2016-07-11 04:05:02.860179) ========= script_repo_revision: 76d556ef9180969ee8d690ed069732faded934a2 ========= Finished set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2016-07-11 04:05:02.860692) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2016-07-11 04:05:02.861005) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2016-07-11 04:05:02.879139) ========= ========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 14 mins, 27 secs) (at 2016-07-11 04:05:02.879548) ========= /tools/buildbot/bin/python scripts/scripts/talos_script.py --suite g4-e10s --add-option --webServer,localhost --branch-name Fx-Team --cfg talos/mac_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Fx-Team in dir /builds/slave/test/. (timeout 3600 secs) (maxTime 7200 secs) watching logfiles {} argv: ['/tools/buildbot/bin/python', 'scripts/scripts/talos_script.py', '--suite', 'g4-e10s', '--add-option', '--webServer,localhost', '--branch-name', 'Fx-Team', '--cfg', 'talos/mac_config.py', '--download-symbols', 'ondemand', '--use-talos-json', '--blob-upload-branch', 'Fx-Team'] environment: Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.60BmflXbZZ/Render GIT_SHARE_BASE_DIR=/builds/git-shared HG_SHARE_BASE_DIR=/builds/hg-shared HOME=/Users/cltbld IDLEIZER_DISABLE_SHUTDOWN=true LOGNAME=cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NO_EM_RESTART=1 PAGER=/bin/cat PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11 PROPERTIES_FILE=/builds/slave/test/buildprops.json PWD=/builds/slave/test RUNNER_CONFIG_CMD=/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg SHELL=/bin/bash SSH_AUTH_SOCK=/private/tmp/com.apple.launchd.MN4hGYEesj/Listeners TMPDIR=/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/ TWISTD_LOG_PATH=/builds/slave/twistd.log USER=cltbld VERSIONER_PYTHON_PREFER_32_BIT=no VERSIONER_PYTHON_VERSION=2.7 XPCOM_DEBUG_BREAK=warn XPC_FLAGS=0x0 XPC_SERVICE_NAME=0 __CF_USER_TEXT_ENCODING=0x1C:0:0 using PTY: False 04:05:03 INFO - MultiFileLogger online at 20160711 04:05:03 in /builds/slave/test 04:05:03 INFO - Run as scripts/scripts/talos_script.py --suite g4-e10s --add-option --webServer,localhost --branch-name Fx-Team --cfg talos/mac_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Fx-Team 04:05:03 INFO - Dumping config to /builds/slave/test/logs/localconfig.json. 04:05:03 INFO - {'append_to_log': False, 04:05:03 INFO - 'base_work_dir': '/builds/slave/test', 04:05:03 INFO - 'blob_upload_branch': 'Fx-Team', 04:05:03 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt', 04:05:03 INFO - 'branch': 'Fx-Team', 04:05:03 INFO - 'buildbot_json_path': 'buildprops.json', 04:05:03 INFO - 'config_files': ('talos/mac_config.py',), 04:05:03 INFO - 'default_actions': ('clobber', 04:05:03 INFO - 'read-buildbot-config', 04:05:03 INFO - 'download-and-extract', 04:05:03 INFO - 'populate-webroot', 04:05:03 INFO - 'create-virtualenv', 04:05:03 INFO - 'install', 04:05:03 INFO - 'run-tests'), 04:05:03 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 04:05:03 INFO - 'download_minidump_stackwalk': True, 04:05:03 INFO - 'download_symbols': 'ondemand', 04:05:03 INFO - 'exes': {'python': '/tools/buildbot/bin/python', 04:05:03 INFO - 'tooltool.py': '/tools/tooltool.py', 04:05:03 INFO - 'virtualenv': ('/tools/buildbot/bin/python', 04:05:03 INFO - '/tools/misc-python/virtualenv.py')}, 04:05:03 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 04:05:03 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 04:05:03 INFO - 'installer_path': 'installer.exe', 04:05:03 INFO - 'log_level': 'info', 04:05:03 INFO - 'log_name': 'talos', 04:05:03 INFO - 'log_to_console': True, 04:05:03 INFO - 'minidump_stackwalk_path': 'macosx64-minidump_stackwalk', 04:05:03 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/macosx64/releng.manifest', 04:05:03 INFO - 'opt_config_files': (), 04:05:03 INFO - 'pip_index': False, 04:05:03 INFO - 'postflight_run_cmd_suites': ({'architectures': ('32bit', '64bit'), 04:05:03 INFO - 'cmd': ('bash', 04:05:03 INFO - '-c', 04:05:03 INFO - 'screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'), 04:05:03 INFO - 'enabled': True, 04:05:03 INFO - 'halt_on_failure': False, 04:05:03 INFO - 'name': 'check_screen_resolution'},), 04:05:03 INFO - 'preflight_run_cmd_suites': ({'architectures': ('32bit', '64bit'), 04:05:03 INFO - 'cmd': ('bash', 04:05:03 INFO - '-c', 04:05:03 INFO - 'screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'), 04:05:03 INFO - 'enabled': True, 04:05:03 INFO - 'halt_on_failure': False, 04:05:03 INFO - 'name': 'check_screen_resolution'},), 04:05:03 INFO - 'run_cmd_checks_enabled': True, 04:05:03 INFO - 'sps_profile': False, 04:05:03 INFO - 'sps_profile_interval': 0, 04:05:03 INFO - 'suite': 'g4-e10s', 04:05:03 INFO - 'system_bits': '32', 04:05:03 INFO - 'talos_extra_options': ('--webServer', 'localhost'), 04:05:03 INFO - 'title': 't-yosemite-r7-0085', 04:05:03 INFO - 'tooltool_cache': '/builds/tooltool_cache', 04:05:03 INFO - 'use_talos_json': True, 04:05:03 INFO - 'virtualenv_path': '/builds/slave/test/build/venv', 04:05:03 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 04:05:03 INFO - 'work_dir': 'build'} 04:05:03 INFO - ##### 04:05:03 INFO - ##### Running clobber step. 04:05:03 INFO - ##### 04:05:03 INFO - Running pre-action listener: _resource_record_pre_action 04:05:03 INFO - Running main action method: clobber 04:05:03 INFO - rmtree: /builds/slave/test/build 04:05:03 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1 04:05:05 INFO - Running post-action listener: _resource_record_post_action 04:05:05 INFO - ##### 04:05:05 INFO - ##### Finished clobber step (success) 04:05:05 INFO - ##### 04:05:05 INFO - ##### 04:05:05 INFO - ##### Running read-buildbot-config step. 04:05:05 INFO - ##### 04:05:05 INFO - Running pre-action listener: _resource_record_pre_action 04:05:05 INFO - Running main action method: read_buildbot_config 04:05:05 INFO - Using buildbot properties: 04:05:05 INFO - { 04:05:05 INFO - "project": "", 04:05:05 INFO - "product": "firefox", 04:05:05 INFO - "script_repo_revision": "production", 04:05:05 INFO - "builddir": "fx-team_yosemite_r7_test-g4-e10s", 04:05:05 INFO - "repository": "", 04:05:05 INFO - "buildername": "Rev7 MacOSX Yosemite 10.10.5 fx-team talos g4-e10s", 04:05:05 INFO - "buildid": "20160711012926", 04:05:05 INFO - "pgo_build": "False", 04:05:05 INFO - "basedir": "/builds/slave/test", 04:05:05 INFO - "buildnumber": 16, 04:05:05 INFO - "slavename": "t-yosemite-r7-0085", 04:05:05 INFO - "master": "http://buildbot-master133.bb.releng.scl3.mozilla.com:8201/", 04:05:05 INFO - "platform": "yosemite_r7", 04:05:05 INFO - "scheduler": "tests-fx-team-macosx64-talos", 04:05:05 INFO - "branch": "fx-team", 04:05:05 INFO - "repo_path": "integration/fx-team", 04:05:05 INFO - "revision": "76d556ef9180969ee8d690ed069732faded934a2", 04:05:05 INFO - "stage_platform": "macosx64", 04:05:05 INFO - "builduid": "4d62b50923894a60ad72f8fe9b9a3f05", 04:05:05 INFO - "slavebuilddir": "test" 04:05:05 INFO - } 04:05:05 INFO - Found installer url https://queue.taskcluster.net/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.dmg. 04:05:05 INFO - Running post-action listener: _resource_record_post_action 04:05:05 INFO - ##### 04:05:05 INFO - ##### Finished read-buildbot-config step (success) 04:05:05 INFO - ##### 04:05:05 INFO - ##### 04:05:05 INFO - ##### Running download-and-extract step. 04:05:05 INFO - ##### 04:05:05 INFO - Running pre-action listener: _resource_record_pre_action 04:05:05 INFO - Running main action method: download_and_extract 04:05:05 INFO - mkdir: /builds/slave/test/build/tests 04:05:05 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 04:05:05 INFO - https://queue.taskcluster.net/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.test_packages.json matches https://queue.taskcluster.net 04:05:05 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.test_packages.json 04:05:05 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.test_packages.json 04:05:05 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.test_packages.json to /builds/slave/test/build/firefox-50.0a1.en-US.mac.test_packages.json 04:05:05 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.test_packages.json', 'file_name': '/builds/slave/test/build/firefox-50.0a1.en-US.mac.test_packages.json'}, attempt #1 04:05:06 INFO - Downloaded 1199 bytes. 04:05:06 INFO - Reading from file /builds/slave/test/build/firefox-50.0a1.en-US.mac.test_packages.json 04:05:06 INFO - Using the following test package requirements: 04:05:06 INFO - {u'common': [u'firefox-50.0a1.en-US.mac.common.tests.zip'], 04:05:06 INFO - u'cppunittest': [u'firefox-50.0a1.en-US.mac.common.tests.zip', 04:05:06 INFO - u'firefox-50.0a1.en-US.mac.cppunittest.tests.zip'], 04:05:06 INFO - u'gtest': [u'firefox-50.0a1.en-US.mac.common.tests.zip', 04:05:06 INFO - u'firefox-50.0a1.en-US.mac.gtest.tests.zip'], 04:05:06 INFO - u'jittest': [u'firefox-50.0a1.en-US.mac.common.tests.zip', 04:05:06 INFO - u'jsshell-mac.zip'], 04:05:06 INFO - u'mochitest': [u'firefox-50.0a1.en-US.mac.common.tests.zip', 04:05:06 INFO - u'firefox-50.0a1.en-US.mac.mochitest.tests.zip'], 04:05:06 INFO - u'mozbase': [u'firefox-50.0a1.en-US.mac.common.tests.zip'], 04:05:06 INFO - u'reftest': [u'firefox-50.0a1.en-US.mac.common.tests.zip', 04:05:06 INFO - u'firefox-50.0a1.en-US.mac.reftest.tests.zip'], 04:05:06 INFO - u'talos': [u'firefox-50.0a1.en-US.mac.common.tests.zip', 04:05:06 INFO - u'firefox-50.0a1.en-US.mac.talos.tests.zip'], 04:05:06 INFO - u'web-platform': [u'firefox-50.0a1.en-US.mac.common.tests.zip', 04:05:06 INFO - u'firefox-50.0a1.en-US.mac.web-platform.tests.zip'], 04:05:06 INFO - u'xpcshell': [u'firefox-50.0a1.en-US.mac.common.tests.zip', 04:05:06 INFO - u'firefox-50.0a1.en-US.mac.xpcshell.tests.zip']} 04:05:06 INFO - Downloading packages: [u'firefox-50.0a1.en-US.mac.common.tests.zip'] for test suite category: common 04:05:06 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 04:05:06 INFO - https://queue.taskcluster.net/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.common.tests.zip matches https://queue.taskcluster.net 04:05:06 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.common.tests.zip 04:05:06 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.common.tests.zip 04:05:06 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.common.tests.zip to /builds/slave/test/build/firefox-50.0a1.en-US.mac.common.tests.zip 04:05:06 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.common.tests.zip', 'file_name': u'/builds/slave/test/build/firefox-50.0a1.en-US.mac.common.tests.zip'}, attempt #1 04:05:08 INFO - Downloaded 18806905 bytes. 04:05:08 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-50.0a1.en-US.mac.common.tests.zip', '-d', '/builds/slave/test/build/tests'] 04:05:08 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-50.0a1.en-US.mac.common.tests.zip -d /builds/slave/test/build/tests 04:05:11 INFO - Return code: 0 04:05:11 INFO - Downloading packages: [u'firefox-50.0a1.en-US.mac.common.tests.zip', u'firefox-50.0a1.en-US.mac.talos.tests.zip'] for test suite category: talos 04:05:11 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 04:05:11 INFO - https://queue.taskcluster.net/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.common.tests.zip matches https://queue.taskcluster.net 04:05:11 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.common.tests.zip 04:05:11 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.common.tests.zip 04:05:11 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.common.tests.zip to /builds/slave/test/build/firefox-50.0a1.en-US.mac.common.tests.zip 04:05:11 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.common.tests.zip', 'file_name': u'/builds/slave/test/build/firefox-50.0a1.en-US.mac.common.tests.zip'}, attempt #1 04:05:12 INFO - Downloaded 18806905 bytes. 04:05:12 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-50.0a1.en-US.mac.common.tests.zip', '-d', '/builds/slave/test/build/tests'] 04:05:12 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-50.0a1.en-US.mac.common.tests.zip -d /builds/slave/test/build/tests 04:05:16 INFO - Return code: 0 04:05:16 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 04:05:16 INFO - https://queue.taskcluster.net/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.talos.tests.zip matches https://queue.taskcluster.net 04:05:16 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.talos.tests.zip 04:05:16 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.talos.tests.zip 04:05:16 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.talos.tests.zip to /builds/slave/test/build/firefox-50.0a1.en-US.mac.talos.tests.zip 04:05:16 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.talos.tests.zip', 'file_name': u'/builds/slave/test/build/firefox-50.0a1.en-US.mac.talos.tests.zip'}, attempt #1 04:05:17 INFO - Downloaded 14403333 bytes. 04:05:17 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-50.0a1.en-US.mac.talos.tests.zip', '-d', '/builds/slave/test/build/tests'] 04:05:17 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-50.0a1.en-US.mac.talos.tests.zip -d /builds/slave/test/build/tests 04:05:17 INFO - Return code: 0 04:05:17 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 04:05:17 INFO - https://queue.taskcluster.net/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.dmg matches https://queue.taskcluster.net 04:05:17 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.dmg 04:05:17 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.dmg 04:05:17 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.dmg to /builds/slave/test/build/firefox-50.0a1.en-US.mac.dmg 04:05:17 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.dmg', 'file_name': '/builds/slave/test/build/firefox-50.0a1.en-US.mac.dmg'}, attempt #1 04:05:21 INFO - Downloaded 112351958 bytes. 04:05:21 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.dmg 04:05:21 INFO - mkdir: /builds/slave/test/properties 04:05:21 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url 04:05:21 INFO - Writing to file /builds/slave/test/properties/build_url 04:05:21 INFO - Contents: 04:05:21 INFO - build_url:https://queue.taskcluster.net/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.dmg 04:05:22 INFO - Running post-action listener: _resource_record_post_action 04:05:22 INFO - Running post-action listener: set_extra_try_arguments 04:05:22 INFO - ##### 04:05:22 INFO - ##### Finished download-and-extract step (success) 04:05:22 INFO - ##### 04:05:22 INFO - ##### 04:05:22 INFO - ##### Running populate-webroot step. 04:05:22 INFO - ##### 04:05:22 INFO - Running pre-action listener: _resource_record_pre_action 04:05:22 INFO - Running main action method: populate_webroot 04:05:22 INFO - {'extra_options': {'android': ['--apkPath=%(apk_path)s']}, 04:05:22 INFO - 'mobile-suites': {'remote-tp4m_nochrome': {'tests': ['tp4m']}, 04:05:22 INFO - 'remote-tsvgx': {'talos_options': ['--noChrome', 04:05:22 INFO - '--tppagecycles', 04:05:22 INFO - '7'], 04:05:22 INFO - 'tests': ['tsvgm']}}, 04:05:22 INFO - 'suites': {'chromez': {'talos_options': ['--disable-e10s'], 04:05:22 INFO - 'tests': ['tresize', 'tcanvasmark']}, 04:05:22 INFO - 'chromez-e10s': {'tests': ['tresize', 'tcanvasmark']}, 04:05:22 INFO - 'dromaeojs': {'talos_options': ['--disable-e10s'], 04:05:22 INFO - 'tests': ['dromaeo_css', 'kraken']}, 04:05:22 INFO - 'dromaeojs-e10s': {'tests': ['dromaeo_css', 'kraken']}, 04:05:22 INFO - 'g1': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 04:05:22 INFO - 'talos_options': ['--disable-e10s'], 04:05:22 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 04:05:22 INFO - 'g1-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 04:05:22 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 04:05:22 INFO - 'g2': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 04:05:22 INFO - 'talos_options': ['--disable-e10s'], 04:05:22 INFO - 'tests': ['damp', 'tps']}, 04:05:22 INFO - 'g2-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 04:05:22 INFO - 'tests': ['damp', 'tps']}, 04:05:22 INFO - 'g3': {'talos_options': ['--disable-e10s'], 04:05:22 INFO - 'tests': ['dromaeo_dom']}, 04:05:22 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']}, 04:05:22 INFO - 'g4': {'talos_options': ['--disable-e10s'], 04:05:22 INFO - 'tests': ['basic_compositor_video']}, 04:05:22 INFO - 'g4-e10s': {'tests': ['basic_compositor_video']}, 04:05:22 INFO - 'other': {'talos_options': ['--disable-e10s'], 04:05:22 INFO - 'tests': ['a11yr', 04:05:22 INFO - 'ts_paint', 04:05:22 INFO - 'tpaint', 04:05:22 INFO - 'sessionrestore', 04:05:22 INFO - 'sessionrestore_no_auto_restore', 04:05:22 INFO - 'tabpaint']}, 04:05:22 INFO - 'other-e10s': {'tests': ['a11yr', 04:05:22 INFO - 'ts_paint', 04:05:22 INFO - 'tpaint', 04:05:22 INFO - 'sessionrestore', 04:05:22 INFO - 'sessionrestore_no_auto_restore', 04:05:22 INFO - 'tabpaint']}, 04:05:22 INFO - 'other-e10s_l64': {'tests': ['a11yr', 04:05:22 INFO - 'ts_paint', 04:05:22 INFO - 'tpaint', 04:05:22 INFO - 'sessionrestore', 04:05:22 INFO - 'sessionrestore_no_auto_restore', 04:05:22 INFO - 'tabpaint']}, 04:05:22 INFO - 'other-e10s_nol64': {'tests': ['a11yr', 04:05:22 INFO - 'ts_paint', 04:05:22 INFO - 'tpaint', 04:05:22 INFO - 'sessionrestore', 04:05:22 INFO - 'sessionrestore_no_auto_restore', 04:05:22 INFO - 'tabpaint']}, 04:05:22 INFO - 'other_l64': {'talos_options': ['--disable-e10s'], 04:05:22 INFO - 'tests': ['a11yr', 04:05:22 INFO - 'ts_paint', 04:05:22 INFO - 'tpaint', 04:05:22 INFO - 'sessionrestore', 04:05:22 INFO - 'sessionrestore_no_auto_restore', 04:05:22 INFO - 'tabpaint']}, 04:05:22 INFO - 'other_nol64': {'talos_options': ['--disable-e10s'], 04:05:22 INFO - 'tests': ['a11yr', 04:05:22 INFO - 'ts_paint', 04:05:22 INFO - 'tpaint', 04:05:22 INFO - 'sessionrestore', 04:05:22 INFO - 'sessionrestore_no_auto_restore', 04:05:22 INFO - 'tabpaint']}, 04:05:22 INFO - 'svgr': {'talos_options': ['--disable-e10s'], 04:05:22 INFO - 'tests': ['tsvgx', 04:05:22 INFO - 'tsvgr_opacity', 04:05:22 INFO - 'tart', 04:05:22 INFO - 'tscrollx', 04:05:22 INFO - 'cart']}, 04:05:22 INFO - 'svgr-e10s': {'tests': ['tsvgx', 04:05:22 INFO - 'tsvgr_opacity', 04:05:22 INFO - 'tart', 04:05:22 INFO - 'tscrollx', 04:05:22 INFO - 'cart']}, 04:05:22 INFO - 'tp5o': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 04:05:22 INFO - 'talos_options': ['--disable-e10s'], 04:05:22 INFO - 'tests': ['tp5o']}, 04:05:22 INFO - 'tp5o-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 04:05:22 INFO - 'tests': ['tp5o']}, 04:05:22 INFO - 'xperf': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 04:05:22 INFO - 'talos_options': ['--disable-e10s', 04:05:22 INFO - '--xperf_path', 04:05:22 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 04:05:22 INFO - 'tests': ['tp5n']}, 04:05:22 INFO - 'xperf-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 04:05:22 INFO - 'talos_options': ['--xperf_path', 04:05:22 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 04:05:22 INFO - 'tests': ['tp5n']}}, 04:05:22 INFO - 'talos.zip': {'path': '', 04:05:22 INFO - 'url': 'http://talos-bundles.pvt.build.mozilla.org/zips/talos.a6052c33d420.zip'}} 04:05:22 INFO - Running post-action listener: _resource_record_post_action 04:05:22 INFO - ##### 04:05:22 INFO - ##### Finished populate-webroot step (success) 04:05:22 INFO - ##### 04:05:22 INFO - ##### 04:05:22 INFO - ##### Running create-virtualenv step. 04:05:22 INFO - ##### 04:05:22 INFO - Running pre-action listener: _resource_record_pre_action 04:05:22 INFO - Running main action method: create_virtualenv 04:05:22 INFO - Creating virtualenv /builds/slave/test/build/venv 04:05:22 INFO - Running command: ['/tools/buildbot/bin/python', '/tools/misc-python/virtualenv.py', '--no-site-packages', '--distribute', '/builds/slave/test/build/venv'] in /builds/slave/test/build 04:05:22 INFO - Copy/paste: /tools/buildbot/bin/python /tools/misc-python/virtualenv.py --no-site-packages --distribute /builds/slave/test/build/venv 04:05:22 INFO - The --no-site-packages flag is deprecated; it is now the default behavior. 04:05:22 INFO - Using real prefix '/tools/python27' 04:05:22 INFO - New python executable in /builds/slave/test/build/venv/bin/python 04:05:23 INFO - Installing distribute.............................................................................................................................................................................................done. 04:05:26 INFO - Installing pip.................done. 04:05:26 INFO - Return code: 0 04:05:26 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv 04:05:26 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 04:05:26 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:05:26 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:05:26 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 04:05:26 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:05:26 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:05:26 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'pip>=1.5']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x108410a30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1084a5618>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fec105c1060>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x108374d30>, 'level': 'warning'}, {'substr': 'Traceback (most recent call last)', 'level': 'error'}, {'substr': 'SyntaxError: ', 'level': 'error'}, {'substr': 'TypeError: ', 'level': 'error'}, {'substr': 'NameError: ', 'level': 'error'}, {'substr': 'ZeroDivisionError: ', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1080d9db0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10836cb20>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'XPC_SERVICE_NAME': '0', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 'HOME': '/Users/cltbld', 'NO_EM_RESTART': '1', 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 'XPCOM_DEBUG_BREAK': 'warn', 'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.60BmflXbZZ/Render', 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 'VERSIONER_PYTHON_VERSION': '2.7', 'XPC_FLAGS': '0x0', 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 'MOZ_NO_REMOTE': '1', 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.MN4hGYEesj/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/', '__CF_USER_TEXT_ENCODING': '0x1C:0:0', 'PWD': '/builds/slave/test', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'PAGER': '/bin/cat'}}, attempt #1 04:05:26 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'pip>=1.5'] in /builds/slave/test/build 04:05:26 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub pip>=1.5 04:05:26 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.60BmflXbZZ/Render', 04:05:26 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 04:05:26 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 04:05:26 INFO - 'HOME': '/Users/cltbld', 04:05:26 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 04:05:26 INFO - 'LOGNAME': 'cltbld', 04:05:26 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:05:26 INFO - 'MOZ_NO_REMOTE': '1', 04:05:26 INFO - 'NO_EM_RESTART': '1', 04:05:26 INFO - 'PAGER': '/bin/cat', 04:05:26 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 04:05:26 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:05:26 INFO - 'PWD': '/builds/slave/test', 04:05:26 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 04:05:26 INFO - 'SHELL': '/bin/bash', 04:05:26 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.MN4hGYEesj/Listeners', 04:05:26 INFO - 'TMPDIR': '/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/', 04:05:26 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 04:05:26 INFO - 'USER': 'cltbld', 04:05:26 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 04:05:26 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 04:05:26 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:05:26 INFO - 'XPC_FLAGS': '0x0', 04:05:26 INFO - 'XPC_SERVICE_NAME': '0', 04:05:26 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0:0'} 04:05:26 INFO - Ignoring indexes: https://pypi.python.org/simple/ 04:05:26 INFO - Requirement already satisfied (use --upgrade to upgrade): pip>=1.5 in ./venv/lib/python2.7/site-packages/pip-1.5.5-py2.7.egg 04:05:26 INFO - Cleaning up... 04:05:26 INFO - Return code: 0 04:05:26 INFO - Installing psutil>=3.1.1 into virtualenv /builds/slave/test/build/venv 04:05:26 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 04:05:26 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:05:26 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:05:26 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 04:05:26 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:05:26 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:05:26 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'psutil>=3.1.1']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x108410a30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1084a5618>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fec105c1060>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x108374d30>, 'level': 'warning'}, {'substr': 'Traceback (most recent call last)', 'level': 'error'}, {'substr': 'SyntaxError: ', 'level': 'error'}, {'substr': 'TypeError: ', 'level': 'error'}, {'substr': 'NameError: ', 'level': 'error'}, {'substr': 'ZeroDivisionError: ', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1080d9db0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10836cb20>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'XPC_SERVICE_NAME': '0', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 'HOME': '/Users/cltbld', 'NO_EM_RESTART': '1', 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 'XPCOM_DEBUG_BREAK': 'warn', 'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.60BmflXbZZ/Render', 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 'VERSIONER_PYTHON_VERSION': '2.7', 'XPC_FLAGS': '0x0', 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 'MOZ_NO_REMOTE': '1', 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.MN4hGYEesj/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/', '__CF_USER_TEXT_ENCODING': '0x1C:0:0', 'PWD': '/builds/slave/test', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'PAGER': '/bin/cat'}}, attempt #1 04:05:26 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'psutil>=3.1.1'] in /builds/slave/test/build 04:05:26 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub psutil>=3.1.1 04:05:26 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.60BmflXbZZ/Render', 04:05:26 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 04:05:26 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 04:05:26 INFO - 'HOME': '/Users/cltbld', 04:05:26 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 04:05:26 INFO - 'LOGNAME': 'cltbld', 04:05:26 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:05:26 INFO - 'MOZ_NO_REMOTE': '1', 04:05:26 INFO - 'NO_EM_RESTART': '1', 04:05:26 INFO - 'PAGER': '/bin/cat', 04:05:26 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 04:05:26 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:05:26 INFO - 'PWD': '/builds/slave/test', 04:05:26 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 04:05:26 INFO - 'SHELL': '/bin/bash', 04:05:26 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.MN4hGYEesj/Listeners', 04:05:26 INFO - 'TMPDIR': '/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/', 04:05:26 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 04:05:26 INFO - 'USER': 'cltbld', 04:05:26 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 04:05:26 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 04:05:26 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:05:26 INFO - 'XPC_FLAGS': '0x0', 04:05:26 INFO - 'XPC_SERVICE_NAME': '0', 04:05:26 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0:0'} 04:05:26 INFO - Ignoring indexes: https://pypi.python.org/simple/ 04:05:26 INFO - Downloading/unpacking psutil>=3.1.1 04:05:26 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:05:26 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:05:26 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:05:26 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:05:26 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:05:26 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:05:29 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/psutil/setup.py) egg_info for package psutil 04:05:29 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 04:05:29 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 04:05:29 INFO - Installing collected packages: psutil 04:05:29 INFO - Running setup.py install for psutil 04:05:29 INFO - building 'psutil._psutil_osx' extension 04:05:29 INFO - gcc -fno-strict-aliasing -g -O2 -DNDEBUG -g -fwrapv -O3 -Wall -Wstrict-prototypes -DPSUTIL_VERSION=311 -I/tools/python27/include/python2.7 -c psutil/_psutil_osx.c -o build/temp.macosx-10.10-x86_64-2.7/psutil/_psutil_osx.o 04:05:30 INFO - gcc -fno-strict-aliasing -g -O2 -DNDEBUG -g -fwrapv -O3 -Wall -Wstrict-prototypes -DPSUTIL_VERSION=311 -I/tools/python27/include/python2.7 -c psutil/_psutil_common.c -o build/temp.macosx-10.10-x86_64-2.7/psutil/_psutil_common.o 04:05:30 INFO - gcc -fno-strict-aliasing -g -O2 -DNDEBUG -g -fwrapv -O3 -Wall -Wstrict-prototypes -DPSUTIL_VERSION=311 -I/tools/python27/include/python2.7 -c psutil/arch/osx/process_info.c -o build/temp.macosx-10.10-x86_64-2.7/psutil/arch/osx/process_info.o 04:05:30 INFO - gcc -bundle -bundle_loader /tools/python27/bin/python2.7 build/temp.macosx-10.10-x86_64-2.7/psutil/_psutil_osx.o build/temp.macosx-10.10-x86_64-2.7/psutil/_psutil_common.o build/temp.macosx-10.10-x86_64-2.7/psutil/arch/osx/process_info.o -o build/lib.macosx-10.10-x86_64-2.7/psutil/_psutil_osx.so -framework CoreFoundation -framework IOKit 04:05:30 INFO - building 'psutil._psutil_posix' extension 04:05:30 INFO - gcc -fno-strict-aliasing -g -O2 -DNDEBUG -g -fwrapv -O3 -Wall -Wstrict-prototypes -I/tools/python27/include/python2.7 -c psutil/_psutil_posix.c -o build/temp.macosx-10.10-x86_64-2.7/psutil/_psutil_posix.o 04:05:30 WARNING - psutil/_psutil_posix.c:403:11: warning: implicit declaration of function 'ioctl' is invalid in C99 [-Wimplicit-function-declaration] 04:05:30 INFO - ret = ioctl(sock, SIOCGIFFLAGS, &ifr); 04:05:30 INFO - ^ 04:05:30 INFO - 1 warning generated. 04:05:30 INFO - gcc -bundle -bundle_loader /tools/python27/bin/python2.7 build/temp.macosx-10.10-x86_64-2.7/psutil/_psutil_posix.o -o build/lib.macosx-10.10-x86_64-2.7/psutil/_psutil_posix.so 04:05:30 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 04:05:30 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 04:05:31 INFO - Successfully installed psutil 04:05:31 INFO - Cleaning up... 04:05:31 INFO - Return code: 0 04:05:31 INFO - Installing mozsystemmonitor==0.3 into virtualenv /builds/slave/test/build/venv 04:05:31 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 04:05:31 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:05:31 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:05:31 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 04:05:31 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:05:31 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:05:31 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'mozsystemmonitor==0.3']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x108410a30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1084a5618>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fec105c1060>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x108374d30>, 'level': 'warning'}, {'substr': 'Traceback (most recent call last)', 'level': 'error'}, {'substr': 'SyntaxError: ', 'level': 'error'}, {'substr': 'TypeError: ', 'level': 'error'}, {'substr': 'NameError: ', 'level': 'error'}, {'substr': 'ZeroDivisionError: ', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1080d9db0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10836cb20>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'XPC_SERVICE_NAME': '0', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 'HOME': '/Users/cltbld', 'NO_EM_RESTART': '1', 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 'XPCOM_DEBUG_BREAK': 'warn', 'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.60BmflXbZZ/Render', 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 'VERSIONER_PYTHON_VERSION': '2.7', 'XPC_FLAGS': '0x0', 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 'MOZ_NO_REMOTE': '1', 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.MN4hGYEesj/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/', '__CF_USER_TEXT_ENCODING': '0x1C:0:0', 'PWD': '/builds/slave/test', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'PAGER': '/bin/cat'}}, attempt #1 04:05:31 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'mozsystemmonitor==0.3'] in /builds/slave/test/build 04:05:31 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub mozsystemmonitor==0.3 04:05:31 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.60BmflXbZZ/Render', 04:05:31 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 04:05:31 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 04:05:31 INFO - 'HOME': '/Users/cltbld', 04:05:31 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 04:05:31 INFO - 'LOGNAME': 'cltbld', 04:05:31 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:05:31 INFO - 'MOZ_NO_REMOTE': '1', 04:05:31 INFO - 'NO_EM_RESTART': '1', 04:05:31 INFO - 'PAGER': '/bin/cat', 04:05:31 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 04:05:31 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:05:31 INFO - 'PWD': '/builds/slave/test', 04:05:31 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 04:05:31 INFO - 'SHELL': '/bin/bash', 04:05:31 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.MN4hGYEesj/Listeners', 04:05:31 INFO - 'TMPDIR': '/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/', 04:05:31 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 04:05:31 INFO - 'USER': 'cltbld', 04:05:31 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 04:05:31 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 04:05:31 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:05:31 INFO - 'XPC_FLAGS': '0x0', 04:05:31 INFO - 'XPC_SERVICE_NAME': '0', 04:05:31 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0:0'} 04:05:31 INFO - Ignoring indexes: https://pypi.python.org/simple/ 04:05:31 INFO - Downloading/unpacking mozsystemmonitor==0.3 04:05:31 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:05:31 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:05:31 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:05:31 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:05:31 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:05:31 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:05:33 INFO - Downloading mozsystemmonitor-0.3.tar.gz 04:05:33 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/mozsystemmonitor/setup.py) egg_info for package mozsystemmonitor 04:05:33 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.3) 04:05:33 INFO - Installing collected packages: mozsystemmonitor 04:05:33 INFO - Running setup.py install for mozsystemmonitor 04:05:33 INFO - Successfully installed mozsystemmonitor 04:05:33 INFO - Cleaning up... 04:05:34 INFO - Return code: 0 04:05:34 INFO - Installing jsonschema==2.5.1 into virtualenv /builds/slave/test/build/venv 04:05:34 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 04:05:34 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:05:34 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:05:34 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 04:05:34 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:05:34 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:05:34 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'jsonschema==2.5.1']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x108410a30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1084a5618>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fec105c1060>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x108374d30>, 'level': 'warning'}, {'substr': 'Traceback (most recent call last)', 'level': 'error'}, {'substr': 'SyntaxError: ', 'level': 'error'}, {'substr': 'TypeError: ', 'level': 'error'}, {'substr': 'NameError: ', 'level': 'error'}, {'substr': 'ZeroDivisionError: ', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1080d9db0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10836cb20>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'XPC_SERVICE_NAME': '0', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 'HOME': '/Users/cltbld', 'NO_EM_RESTART': '1', 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 'XPCOM_DEBUG_BREAK': 'warn', 'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.60BmflXbZZ/Render', 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 'VERSIONER_PYTHON_VERSION': '2.7', 'XPC_FLAGS': '0x0', 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 'MOZ_NO_REMOTE': '1', 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.MN4hGYEesj/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/', '__CF_USER_TEXT_ENCODING': '0x1C:0:0', 'PWD': '/builds/slave/test', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'PAGER': '/bin/cat'}}, attempt #1 04:05:34 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'jsonschema==2.5.1'] in /builds/slave/test/build 04:05:34 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub jsonschema==2.5.1 04:05:34 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.60BmflXbZZ/Render', 04:05:34 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 04:05:34 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 04:05:34 INFO - 'HOME': '/Users/cltbld', 04:05:34 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 04:05:34 INFO - 'LOGNAME': 'cltbld', 04:05:34 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:05:34 INFO - 'MOZ_NO_REMOTE': '1', 04:05:34 INFO - 'NO_EM_RESTART': '1', 04:05:34 INFO - 'PAGER': '/bin/cat', 04:05:34 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 04:05:34 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:05:34 INFO - 'PWD': '/builds/slave/test', 04:05:34 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 04:05:34 INFO - 'SHELL': '/bin/bash', 04:05:34 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.MN4hGYEesj/Listeners', 04:05:34 INFO - 'TMPDIR': '/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/', 04:05:34 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 04:05:34 INFO - 'USER': 'cltbld', 04:05:34 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 04:05:34 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 04:05:34 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:05:34 INFO - 'XPC_FLAGS': '0x0', 04:05:34 INFO - 'XPC_SERVICE_NAME': '0', 04:05:34 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0:0'} 04:05:34 INFO - Ignoring indexes: https://pypi.python.org/simple/ 04:05:34 INFO - Downloading/unpacking jsonschema==2.5.1 04:05:34 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:05:34 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:05:34 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:05:34 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:05:34 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:05:34 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:05:36 INFO - Downloading jsonschema-2.5.1-py2.py3-none-any.whl 04:05:36 INFO - Downloading/unpacking functools32 (from jsonschema==2.5.1) 04:05:36 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:05:36 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:05:36 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:05:36 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:05:36 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:05:36 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:05:37 INFO - Downloading functools32-3.2.3-2.tar.gz 04:05:37 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/functools32/setup.py) egg_info for package functools32 04:05:37 INFO - warning: no files found matching '*.txt' 04:05:37 INFO - no previously-included directories found matching 'build' 04:05:37 INFO - no previously-included directories found matching 'dist' 04:05:37 INFO - no previously-included directories found matching '.git*' 04:05:37 INFO - Installing collected packages: jsonschema, functools32 04:05:37 INFO - Running setup.py install for functools32 04:05:37 INFO - warning: no files found matching '*.txt' 04:05:37 INFO - no previously-included directories found matching 'build' 04:05:37 INFO - no previously-included directories found matching 'dist' 04:05:37 INFO - no previously-included directories found matching '.git*' 04:05:37 INFO - Successfully installed jsonschema functools32 04:05:37 INFO - Cleaning up... 04:05:37 INFO - Return code: 0 04:05:37 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv 04:05:37 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 04:05:37 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:05:37 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:05:37 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 04:05:37 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:05:37 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:05:37 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'blobuploader==1.2.4']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x108410a30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1084a5618>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fec105c1060>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x108374d30>, 'level': 'warning'}, {'substr': 'Traceback (most recent call last)', 'level': 'error'}, {'substr': 'SyntaxError: ', 'level': 'error'}, {'substr': 'TypeError: ', 'level': 'error'}, {'substr': 'NameError: ', 'level': 'error'}, {'substr': 'ZeroDivisionError: ', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1080d9db0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10836cb20>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'XPC_SERVICE_NAME': '0', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 'HOME': '/Users/cltbld', 'NO_EM_RESTART': '1', 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 'XPCOM_DEBUG_BREAK': 'warn', 'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.60BmflXbZZ/Render', 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 'VERSIONER_PYTHON_VERSION': '2.7', 'XPC_FLAGS': '0x0', 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 'MOZ_NO_REMOTE': '1', 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.MN4hGYEesj/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/', '__CF_USER_TEXT_ENCODING': '0x1C:0:0', 'PWD': '/builds/slave/test', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'PAGER': '/bin/cat'}}, attempt #1 04:05:37 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'blobuploader==1.2.4'] in /builds/slave/test/build 04:05:37 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub blobuploader==1.2.4 04:05:37 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.60BmflXbZZ/Render', 04:05:37 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 04:05:37 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 04:05:37 INFO - 'HOME': '/Users/cltbld', 04:05:37 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 04:05:37 INFO - 'LOGNAME': 'cltbld', 04:05:37 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:05:37 INFO - 'MOZ_NO_REMOTE': '1', 04:05:37 INFO - 'NO_EM_RESTART': '1', 04:05:37 INFO - 'PAGER': '/bin/cat', 04:05:37 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 04:05:37 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:05:37 INFO - 'PWD': '/builds/slave/test', 04:05:37 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 04:05:37 INFO - 'SHELL': '/bin/bash', 04:05:37 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.MN4hGYEesj/Listeners', 04:05:37 INFO - 'TMPDIR': '/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/', 04:05:37 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 04:05:37 INFO - 'USER': 'cltbld', 04:05:37 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 04:05:37 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 04:05:37 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:05:37 INFO - 'XPC_FLAGS': '0x0', 04:05:37 INFO - 'XPC_SERVICE_NAME': '0', 04:05:37 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0:0'} 04:05:37 INFO - Ignoring indexes: https://pypi.python.org/simple/ 04:05:37 INFO - Downloading/unpacking blobuploader==1.2.4 04:05:37 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:05:37 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:05:37 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:05:37 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:05:37 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:05:37 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:05:40 INFO - Downloading blobuploader-1.2.4.tar.gz 04:05:40 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blobuploader/setup.py) egg_info for package blobuploader 04:05:40 INFO - Downloading/unpacking requests==1.2.3. (from blobuploader==1.2.4) 04:05:40 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:05:40 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:05:40 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:05:40 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:05:40 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:05:40 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:05:40 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests 04:05:41 INFO - Downloading/unpacking docopt==0.6.1 (from blobuploader==1.2.4) 04:05:41 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:05:41 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:05:41 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:05:41 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:05:41 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:05:41 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:05:41 INFO - Downloading docopt-0.6.1.tar.gz 04:05:41 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/docopt/setup.py) egg_info for package docopt 04:05:41 INFO - Installing collected packages: blobuploader, requests, docopt 04:05:41 INFO - Running setup.py install for blobuploader 04:05:41 INFO - changing mode of build/scripts-2.7/blobberc.py from 664 to 775 04:05:41 INFO - changing mode of /builds/slave/test/build/venv/bin/blobberc.py to 775 04:05:41 INFO - Running setup.py install for requests 04:05:42 INFO - Running setup.py install for docopt 04:05:42 INFO - Successfully installed blobuploader requests docopt 04:05:42 INFO - Cleaning up... 04:05:42 INFO - Return code: 0 04:05:42 INFO - Installing None into virtualenv /builds/slave/test/build/venv 04:05:42 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 04:05:42 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:05:42 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:05:42 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 04:05:42 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:05:42 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:05:42 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x108410a30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1084a5618>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fec105c1060>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x108374d30>, 'level': 'warning'}, {'substr': 'Traceback (most recent call last)', 'level': 'error'}, {'substr': 'SyntaxError: ', 'level': 'error'}, {'substr': 'TypeError: ', 'level': 'error'}, {'substr': 'NameError: ', 'level': 'error'}, {'substr': 'ZeroDivisionError: ', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1080d9db0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10836cb20>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build/tests/config', 'env': {'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'XPC_SERVICE_NAME': '0', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 'HOME': '/Users/cltbld', 'NO_EM_RESTART': '1', 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 'XPCOM_DEBUG_BREAK': 'warn', 'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.60BmflXbZZ/Render', 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 'VERSIONER_PYTHON_VERSION': '2.7', 'XPC_FLAGS': '0x0', 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 'MOZ_NO_REMOTE': '1', 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.MN4hGYEesj/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/', '__CF_USER_TEXT_ENCODING': '0x1C:0:0', 'PWD': '/builds/slave/test', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'PAGER': '/bin/cat'}}, attempt #1 04:05:42 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/config 04:05:42 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --no-deps --timeout 120 -r /builds/slave/test/build/tests/config/mozbase_requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub 04:05:42 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.60BmflXbZZ/Render', 04:05:42 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 04:05:42 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 04:05:42 INFO - 'HOME': '/Users/cltbld', 04:05:42 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 04:05:42 INFO - 'LOGNAME': 'cltbld', 04:05:42 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:05:42 INFO - 'MOZ_NO_REMOTE': '1', 04:05:42 INFO - 'NO_EM_RESTART': '1', 04:05:42 INFO - 'PAGER': '/bin/cat', 04:05:42 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 04:05:42 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:05:42 INFO - 'PWD': '/builds/slave/test', 04:05:42 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 04:05:42 INFO - 'SHELL': '/bin/bash', 04:05:42 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.MN4hGYEesj/Listeners', 04:05:42 INFO - 'TMPDIR': '/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/', 04:05:42 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 04:05:42 INFO - 'USER': 'cltbld', 04:05:42 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 04:05:42 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 04:05:42 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:05:42 INFO - 'XPC_FLAGS': '0x0', 04:05:42 INFO - 'XPC_SERVICE_NAME': '0', 04:05:42 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0:0'} 04:05:43 INFO - Ignoring indexes: https://pypi.python.org/simple/ 04:05:43 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 04:05:43 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-_hMz59-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 04:05:43 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 04:05:43 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-ZunMIp-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 04:05:43 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 04:05:43 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-SSCBTf-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 04:05:43 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 04:05:43 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-Bu3B97-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 04:05:43 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 04:05:43 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-np4JiS-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 04:05:43 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 04:05:43 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-EYEDSz-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 04:05:43 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 04:05:43 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-7ZYE8W-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 04:05:43 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 04:05:43 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-8EEv0f-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 04:05:44 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 04:05:44 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-IyXcdr-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 04:05:44 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 04:05:44 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-zaM6BB-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 04:05:44 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 04:05:44 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-IQHBTH-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 04:05:44 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 04:05:44 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-7icRrZ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 04:05:44 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 04:05:44 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-czJEYc-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 04:05:44 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 04:05:44 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-z0nHV5-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 04:05:44 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 04:05:44 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-z7kwaB-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 04:05:44 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 04:05:44 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-RI7VGk-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 04:05:44 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 04:05:44 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-YgmagJ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 04:05:45 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion 04:05:45 INFO - Running setup.py install for manifestparser 04:05:45 INFO - Installing manifestparser script to /builds/slave/test/build/venv/bin 04:05:45 INFO - Running setup.py install for mozcrash 04:05:45 INFO - Running setup.py install for mozdebug 04:05:45 INFO - Running setup.py install for mozdevice 04:05:45 INFO - Installing sutini script to /builds/slave/test/build/venv/bin 04:05:45 INFO - Installing dm script to /builds/slave/test/build/venv/bin 04:05:45 INFO - Running setup.py install for mozfile 04:05:45 INFO - Running setup.py install for mozhttpd 04:05:45 INFO - Installing mozhttpd script to /builds/slave/test/build/venv/bin 04:05:45 INFO - Running setup.py install for mozinfo 04:05:46 INFO - Installing mozinfo script to /builds/slave/test/build/venv/bin 04:05:46 INFO - Running setup.py install for mozInstall 04:05:46 INFO - Installing moz_remove_from_system script to /builds/slave/test/build/venv/bin 04:05:46 INFO - Installing mozuninstall script to /builds/slave/test/build/venv/bin 04:05:46 INFO - Installing mozinstall script to /builds/slave/test/build/venv/bin 04:05:46 INFO - Installing moz_add_to_system script to /builds/slave/test/build/venv/bin 04:05:46 INFO - Running setup.py install for mozleak 04:05:46 INFO - Running setup.py install for mozlog 04:05:46 INFO - Installing structlog script to /builds/slave/test/build/venv/bin 04:05:46 INFO - Running setup.py install for moznetwork 04:05:46 INFO - Installing moznetwork script to /builds/slave/test/build/venv/bin 04:05:46 INFO - Running setup.py install for mozprocess 04:05:46 INFO - Running setup.py install for mozprofile 04:05:46 INFO - Installing mozprofile script to /builds/slave/test/build/venv/bin 04:05:46 INFO - Installing diff-profiles script to /builds/slave/test/build/venv/bin 04:05:46 INFO - Installing view-profile script to /builds/slave/test/build/venv/bin 04:05:47 INFO - Running setup.py install for mozrunner 04:05:47 INFO - Installing mozrunner script to /builds/slave/test/build/venv/bin 04:05:47 INFO - Running setup.py install for mozscreenshot 04:05:47 INFO - Running setup.py install for moztest 04:05:47 INFO - Running setup.py install for mozversion 04:05:47 INFO - Installing mozversion script to /builds/slave/test/build/venv/bin 04:05:47 INFO - Successfully installed manifestparser mozcrash mozdebug mozdevice mozfile mozhttpd mozinfo mozInstall mozleak mozlog moznetwork mozprocess mozprofile mozrunner mozscreenshot moztest mozversion 04:05:47 INFO - Cleaning up... 04:05:47 INFO - Return code: 0 04:05:47 INFO - Installing None into virtualenv /builds/slave/test/build/venv 04:05:47 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 04:05:47 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:05:47 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:05:47 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 04:05:47 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:05:47 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:05:47 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x108410a30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1084a5618>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fec105c1060>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x108374d30>, 'level': 'warning'}, {'substr': 'Traceback (most recent call last)', 'level': 'error'}, {'substr': 'SyntaxError: ', 'level': 'error'}, {'substr': 'TypeError: ', 'level': 'error'}, {'substr': 'NameError: ', 'level': 'error'}, {'substr': 'ZeroDivisionError: ', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1080d9db0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10836cb20>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build/tests/config', 'env': {'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'XPC_SERVICE_NAME': '0', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 'HOME': '/Users/cltbld', 'NO_EM_RESTART': '1', 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 'XPCOM_DEBUG_BREAK': 'warn', 'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.60BmflXbZZ/Render', 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 'VERSIONER_PYTHON_VERSION': '2.7', 'XPC_FLAGS': '0x0', 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 'MOZ_NO_REMOTE': '1', 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.MN4hGYEesj/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/', '__CF_USER_TEXT_ENCODING': '0x1C:0:0', 'PWD': '/builds/slave/test', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'PAGER': '/bin/cat'}}, attempt #1 04:05:47 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/config 04:05:47 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 -r /builds/slave/test/build/tests/config/mozbase_requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub 04:05:47 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.60BmflXbZZ/Render', 04:05:47 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 04:05:47 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 04:05:47 INFO - 'HOME': '/Users/cltbld', 04:05:47 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 04:05:47 INFO - 'LOGNAME': 'cltbld', 04:05:47 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:05:47 INFO - 'MOZ_NO_REMOTE': '1', 04:05:47 INFO - 'NO_EM_RESTART': '1', 04:05:47 INFO - 'PAGER': '/bin/cat', 04:05:47 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 04:05:47 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:05:47 INFO - 'PWD': '/builds/slave/test', 04:05:47 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 04:05:47 INFO - 'SHELL': '/bin/bash', 04:05:47 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.MN4hGYEesj/Listeners', 04:05:47 INFO - 'TMPDIR': '/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/', 04:05:47 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 04:05:47 INFO - 'USER': 'cltbld', 04:05:47 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 04:05:47 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 04:05:47 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:05:47 INFO - 'XPC_FLAGS': '0x0', 04:05:47 INFO - 'XPC_SERVICE_NAME': '0', 04:05:47 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0:0'} 04:05:47 INFO - Ignoring indexes: https://pypi.python.org/simple/ 04:05:47 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 04:05:47 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-2YvbE1-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 04:05:48 INFO - Requirement already satisfied (use --upgrade to upgrade): manifestparser==1.1 from file:///builds/slave/test/build/tests/mozbase/manifestparser in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 1)) 04:05:48 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 04:05:48 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-eQaPuy-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 04:05:48 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash==0.17 from file:///builds/slave/test/build/tests/mozbase/mozcrash in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2)) 04:05:48 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 04:05:48 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-eFufDc-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 04:05:48 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdebug==0.1 from file:///builds/slave/test/build/tests/mozbase/mozdebug in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 3)) 04:05:48 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 04:05:48 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-olzBSl-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 04:05:48 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdevice==0.48 from file:///builds/slave/test/build/tests/mozbase/mozdevice in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4)) 04:05:48 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 04:05:48 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-R0TJie-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 04:05:48 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile==1.2 from file:///builds/slave/test/build/tests/mozbase/mozfile in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 5)) 04:05:48 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 04:05:48 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-JSP0Zu-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 04:05:48 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd==0.7 from file:///builds/slave/test/build/tests/mozbase/mozhttpd in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 6)) 04:05:48 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 04:05:48 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-SwI7w2-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 04:05:48 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo==0.9 from file:///builds/slave/test/build/tests/mozbase/mozinfo in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 7)) 04:05:48 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 04:05:48 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-twNOHi-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 04:05:48 INFO - Requirement already satisfied (use --upgrade to upgrade): mozInstall==1.12 from file:///builds/slave/test/build/tests/mozbase/mozinstall in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 8)) 04:05:48 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 04:05:48 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-YeeRdM-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 04:05:48 INFO - Requirement already satisfied (use --upgrade to upgrade): mozleak==0.1 from file:///builds/slave/test/build/tests/mozbase/mozleak in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 9)) 04:05:48 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 04:05:48 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-GNXwFr-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 04:05:49 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog==3.2 from file:///builds/slave/test/build/tests/mozbase/mozlog in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 04:05:49 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 04:05:49 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-oYVLp5-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 04:05:49 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork==0.27 from file:///builds/slave/test/build/tests/mozbase/moznetwork in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 11)) 04:05:49 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 04:05:49 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-GebYOV-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 04:05:49 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess==0.23 from file:///builds/slave/test/build/tests/mozbase/mozprocess in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 12)) 04:05:49 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 04:05:49 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-DQRKcG-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 04:05:49 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile==0.28 from file:///builds/slave/test/build/tests/mozbase/mozprofile in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 13)) 04:05:49 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 04:05:49 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-hnxODI-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 04:05:49 INFO - Requirement already satisfied (use --upgrade to upgrade): mozrunner==6.12 from file:///builds/slave/test/build/tests/mozbase/mozrunner in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 14)) 04:05:49 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 04:05:49 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-5UDXSf-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 04:05:49 INFO - Requirement already satisfied (use --upgrade to upgrade): mozscreenshot==0.1 from file:///builds/slave/test/build/tests/mozbase/mozscreenshot in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 15)) 04:05:49 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 04:05:49 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-FClptA-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 04:05:49 INFO - Requirement already satisfied (use --upgrade to upgrade): moztest==0.7 from file:///builds/slave/test/build/tests/mozbase/moztest in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 16)) 04:05:49 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 04:05:49 INFO - Running setup.py (path:/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/pip-PPXK1M-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 04:05:49 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion==1.4 from file:///builds/slave/test/build/tests/mozbase/mozversion in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 17)) 04:05:49 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozcrash==0.17->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2)) 04:05:49 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozcrash==0.17->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2)) 04:05:49 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozdebug==0.1->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 3)) 04:05:49 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork>=0.24 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozdevice==0.48->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4)) 04:05:49 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.19 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozdevice==0.48->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4)) 04:05:49 INFO - Downloading/unpacking blessings>=1.3 (from mozlog==3.2->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 04:05:49 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:05:49 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:05:49 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:05:49 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:05:49 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:05:49 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:05:52 INFO - Downloading blessings-1.6.tar.gz 04:05:52 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blessings/setup.py) egg_info for package blessings 04:05:52 INFO - Installing collected packages: blessings 04:05:52 INFO - Running setup.py install for blessings 04:05:52 INFO - Successfully installed blessings 04:05:52 INFO - Cleaning up... 04:05:52 INFO - Return code: 0 04:05:52 INFO - Done creating virtualenv /builds/slave/test/build/venv. 04:05:52 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 04:05:52 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 04:05:52 INFO - Reading from file tmpfile_stdout 04:05:52 INFO - Current package versions: 04:05:52 INFO - blessings == 1.6 04:05:52 INFO - blobuploader == 1.2.4 04:05:52 INFO - docopt == 0.6.1 04:05:52 INFO - functools32 == 3.2.3-2 04:05:52 INFO - jsonschema == 2.5.1 04:05:52 INFO - manifestparser == 1.1 04:05:52 INFO - mozInstall == 1.12 04:05:52 INFO - mozcrash == 0.17 04:05:52 INFO - mozdebug == 0.1 04:05:52 INFO - mozdevice == 0.48 04:05:52 INFO - mozfile == 1.2 04:05:52 INFO - mozhttpd == 0.7 04:05:52 INFO - mozinfo == 0.9 04:05:52 INFO - mozleak == 0.1 04:05:52 INFO - mozlog == 3.2 04:05:52 INFO - moznetwork == 0.27 04:05:52 INFO - mozprocess == 0.23 04:05:52 INFO - mozprofile == 0.28 04:05:52 INFO - mozrunner == 6.12 04:05:52 INFO - mozscreenshot == 0.1 04:05:52 INFO - mozsystemmonitor == 0.3 04:05:52 INFO - moztest == 0.7 04:05:52 INFO - mozversion == 1.4 04:05:52 INFO - psutil == 3.1.1 04:05:52 INFO - requests == 1.2.3 04:05:52 INFO - wsgiref == 0.1.2 04:05:52 INFO - Installing None into virtualenv /builds/slave/test/build/venv 04:05:52 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 04:05:52 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:05:52 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:05:52 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 04:05:52 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:05:52 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:05:52 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '-r', '/builds/slave/test/build/tests/talos/requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x108410a30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1084a5618>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fec105c1060>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x108374d30>, 'level': 'warning'}, {'substr': 'Traceback (most recent call last)', 'level': 'error'}, {'substr': 'SyntaxError: ', 'level': 'error'}, {'substr': 'TypeError: ', 'level': 'error'}, {'substr': 'NameError: ', 'level': 'error'}, {'substr': 'ZeroDivisionError: ', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1080d9db0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10836cb20>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build/tests/talos', 'env': {'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'XPC_SERVICE_NAME': '0', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 'HOME': '/Users/cltbld', 'NO_EM_RESTART': '1', 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 'XPCOM_DEBUG_BREAK': 'warn', 'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.60BmflXbZZ/Render', 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 'VERSIONER_PYTHON_VERSION': '2.7', 'XPC_FLAGS': '0x0', 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 'MOZ_NO_REMOTE': '1', 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.MN4hGYEesj/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/', '__CF_USER_TEXT_ENCODING': '0x1C:0:0', 'PWD': '/builds/slave/test', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'PAGER': '/bin/cat'}}, attempt #1 04:05:52 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '-r', '/builds/slave/test/build/tests/talos/requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/talos 04:05:52 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 -r /builds/slave/test/build/tests/talos/requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub 04:05:52 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.60BmflXbZZ/Render', 04:05:52 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 04:05:52 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 04:05:52 INFO - 'HOME': '/Users/cltbld', 04:05:52 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 04:05:52 INFO - 'LOGNAME': 'cltbld', 04:05:52 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:05:52 INFO - 'MOZ_NO_REMOTE': '1', 04:05:52 INFO - 'NO_EM_RESTART': '1', 04:05:52 INFO - 'PAGER': '/bin/cat', 04:05:52 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 04:05:52 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:05:52 INFO - 'PWD': '/builds/slave/test', 04:05:52 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 04:05:52 INFO - 'SHELL': '/bin/bash', 04:05:52 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.MN4hGYEesj/Listeners', 04:05:52 INFO - 'TMPDIR': '/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/', 04:05:52 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 04:05:52 INFO - 'USER': 'cltbld', 04:05:52 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 04:05:52 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 04:05:52 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:05:52 INFO - 'XPC_FLAGS': '0x0', 04:05:52 INFO - 'XPC_SERVICE_NAME': '0', 04:05:52 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0:0'} 04:05:53 INFO - Ignoring indexes: https://pypi.python.org/simple/ 04:05:53 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.1 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 1)) 04:05:53 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash>=0.15 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 2)) 04:05:53 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.2 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 3)) 04:05:53 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd>=0.7 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 4)) 04:05:53 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo>=0.8 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 5)) 04:05:53 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.22 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 6)) 04:05:53 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion>=1.3 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 7)) 04:05:53 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile>=0.25 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 8)) 04:05:53 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 9)) 04:05:53 INFO - Requirement already satisfied (use --upgrade to upgrade): blessings>=1.3 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozlog>=3.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 1)) 04:05:53 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork>=0.24 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozhttpd>=0.7->-r /builds/slave/test/build/tests/talos/requirements.txt (line 4)) 04:05:53 INFO - Cleaning up... 04:05:53 INFO - Return code: 0 04:05:53 INFO - Installing jsonschema into virtualenv /builds/slave/test/build/venv 04:05:53 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 04:05:53 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:05:53 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:05:53 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 04:05:53 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:05:53 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:05:53 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'jsonschema']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x108410a30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1084a5618>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fec105c1060>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x108374d30>, 'level': 'warning'}, {'substr': 'Traceback (most recent call last)', 'level': 'error'}, {'substr': 'SyntaxError: ', 'level': 'error'}, {'substr': 'TypeError: ', 'level': 'error'}, {'substr': 'NameError: ', 'level': 'error'}, {'substr': 'ZeroDivisionError: ', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1080d9db0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10836cb20>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'XPC_SERVICE_NAME': '0', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 'HOME': '/Users/cltbld', 'NO_EM_RESTART': '1', 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 'XPCOM_DEBUG_BREAK': 'warn', 'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.60BmflXbZZ/Render', 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 'VERSIONER_PYTHON_VERSION': '2.7', 'XPC_FLAGS': '0x0', 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 'MOZ_NO_REMOTE': '1', 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.MN4hGYEesj/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/', '__CF_USER_TEXT_ENCODING': '0x1C:0:0', 'PWD': '/builds/slave/test', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'PAGER': '/bin/cat'}}, attempt #1 04:05:53 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'jsonschema'] in /builds/slave/test/build 04:05:53 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub jsonschema 04:05:53 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.60BmflXbZZ/Render', 04:05:53 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 04:05:53 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 04:05:53 INFO - 'HOME': '/Users/cltbld', 04:05:53 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 04:05:53 INFO - 'LOGNAME': 'cltbld', 04:05:53 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:05:53 INFO - 'MOZ_NO_REMOTE': '1', 04:05:53 INFO - 'NO_EM_RESTART': '1', 04:05:53 INFO - 'PAGER': '/bin/cat', 04:05:53 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 04:05:53 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:05:53 INFO - 'PWD': '/builds/slave/test', 04:05:53 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 04:05:53 INFO - 'SHELL': '/bin/bash', 04:05:53 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.MN4hGYEesj/Listeners', 04:05:53 INFO - 'TMPDIR': '/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/', 04:05:53 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 04:05:53 INFO - 'USER': 'cltbld', 04:05:53 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 04:05:53 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 04:05:53 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:05:53 INFO - 'XPC_FLAGS': '0x0', 04:05:53 INFO - 'XPC_SERVICE_NAME': '0', 04:05:53 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0:0'} 04:05:53 INFO - Ignoring indexes: https://pypi.python.org/simple/ 04:05:53 INFO - Requirement already satisfied (use --upgrade to upgrade): jsonschema in ./venv/lib/python2.7/site-packages 04:05:53 INFO - Cleaning up... 04:05:53 INFO - Return code: 0 04:05:53 INFO - Running post-action listener: _resource_record_post_action 04:05:53 INFO - Running post-action listener: _start_resource_monitoring 04:05:53 INFO - Starting resource monitoring. 04:05:53 INFO - ##### 04:05:53 INFO - ##### Finished create-virtualenv step (success) 04:05:53 INFO - ##### 04:05:53 INFO - ##### 04:05:53 INFO - ##### Running install step. 04:05:53 INFO - ##### 04:05:53 INFO - Running pre-action listener: _resource_record_pre_action 04:05:53 INFO - Running main action method: install 04:05:53 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 04:05:53 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 04:05:53 INFO - Reading from file tmpfile_stdout 04:05:53 INFO - Detecting whether we're running mozinstall >=1.0... 04:05:53 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h'] 04:05:53 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h 04:05:53 INFO - Reading from file tmpfile_stdout 04:05:53 INFO - Output received: 04:05:53 INFO - Usage: mozinstall [options] installer 04:05:53 INFO - Options: 04:05:53 INFO - -h, --help show this help message and exit 04:05:53 INFO - -d DEST, --destination=DEST 04:05:53 INFO - Directory to install application into. [default: 04:05:53 INFO - "/builds/slave/test"] 04:05:53 INFO - --app=APP Application being installed. [default: firefox] 04:05:53 INFO - mkdir: /builds/slave/test/build/application 04:05:53 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '/builds/slave/test/build/firefox-50.0a1.en-US.mac.dmg', '--destination', '/builds/slave/test/build/application'] 04:05:53 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall /builds/slave/test/build/firefox-50.0a1.en-US.mac.dmg --destination /builds/slave/test/build/application 04:06:28 INFO - Reading from file tmpfile_stdout 04:06:28 INFO - Output received: 04:06:28 INFO - /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox 04:06:28 INFO - Running post-action listener: _resource_record_post_action 04:06:28 INFO - ##### 04:06:28 INFO - ##### Finished install step (success) 04:06:28 INFO - ##### 04:06:28 INFO - ##### 04:06:28 INFO - ##### Running run-tests step. 04:06:28 INFO - ##### 04:06:28 INFO - Running pre-action listener: _resource_record_pre_action 04:06:28 INFO - Running main action method: run_tests 04:06:28 INFO - Running pre test command check_screen_resolution with 'bash -c screenresolution get && screenresolution list && system_profiler SPDisplaysDataType' 04:06:28 INFO - Running command: ['bash', '-c', 'screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'] in /builds/slave/test/build 04:06:28 INFO - Copy/paste: bash -c "screenresolution get && screenresolution list && system_profiler SPDisplaysDataType" 04:06:28 INFO - 2016-07-11 04:06:28.750 screenresolution[1638:7559] starting screenresolution argv=screenresolution get 04:06:28 INFO - 2016-07-11 04:06:28.753 screenresolution[1638:7559] Display 0: 1600x1200x32@60 04:06:28 INFO - 2016-07-11 04:06:28.759 screenresolution[1639:7561] starting screenresolution argv=screenresolution list 04:06:28 INFO - Available Modes on Display 0 04:06:28 INFO - 1600x1200x32@60 1152x870x32@75 1280x1024x32@75 04:06:28 INFO - 1024x768x32@75 1024x768x32@70 1024x768x32@60 04:06:28 INFO - 800x600x32@75 800x600x32@60 640x480x32@75 04:06:28 INFO - 640x480x32@60 1280x1024x32@60 1280x960x32@60 04:06:28 INFO - 1280x960x32@75 1344x1008x32@60 Graphics/Displays: 04:06:28 INFO - Intel Iris: 04:06:28 INFO - Chipset Model: Intel Iris 04:06:28 INFO - Type: GPU 04:06:28 INFO - Bus: Built-In 04:06:28 INFO - VRAM (Dynamic, Max): 1536 MB 04:06:28 INFO - Vendor: Intel (0x8086) 04:06:28 INFO - Device ID: 0x0a2e 04:06:28 INFO - Revision ID: 0x0009 04:06:28 INFO - Displays: 04:06:28 INFO - Display: 04:06:28 INFO - Resolution: 1600 x 1200 @ 60 Hz 04:06:28 INFO - Pixel Depth: 32-Bit Color (ARGB8888) 04:06:28 INFO - Display Serial Number: 1600x1200 60 04:06:28 INFO - Main Display: Yes 04:06:28 INFO - Mirror: Off 04:06:28 INFO - Online: Yes 04:06:28 INFO - Rotation: Supported 04:06:28 INFO - Return code: 0 04:06:28 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version'] 04:06:28 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version 04:06:28 INFO - Python 2.7.3 04:06:28 INFO - Return code: 0 04:06:28 INFO - grabbing minidump binary from tooltool 04:06:28 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 04:06:28 INFO - retry: Calling run_command with args: (['/tools/tooltool.py', '--url', 'https://api.pub.build.mozilla.org/tooltool/', '--authentication-file', '/builds/relengapi.tok', 'fetch', '-m', '/builds/slave/test/build/tests/config/tooltool-manifests/macosx64/releng.manifest', '-o', '-c', '/builds/tooltool_cache'],), kwargs: {'output_timeout': 600, 'error_list': [{'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x108374d30>, 'level': 'warning'}, {'substr': 'Traceback (most recent call last)', 'level': 'error'}, {'substr': 'SyntaxError: ', 'level': 'error'}, {'substr': 'TypeError: ', 'level': 'error'}, {'substr': 'NameError: ', 'level': 'error'}, {'substr': 'ZeroDivisionError: ', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1080d9db0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10836cb20>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1 04:06:28 INFO - Running command: ['/tools/tooltool.py', '--url', 'https://api.pub.build.mozilla.org/tooltool/', '--authentication-file', '/builds/relengapi.tok', 'fetch', '-m', '/builds/slave/test/build/tests/config/tooltool-manifests/macosx64/releng.manifest', '-o', '-c', '/builds/tooltool_cache'] in /builds/slave/test/build 04:06:28 INFO - Copy/paste: /tools/tooltool.py --url https://api.pub.build.mozilla.org/tooltool/ --authentication-file /builds/relengapi.tok fetch -m /builds/slave/test/build/tests/config/tooltool-manifests/macosx64/releng.manifest -o -c /builds/tooltool_cache 04:06:28 INFO - Calling ['/tools/tooltool.py', '--url', 'https://api.pub.build.mozilla.org/tooltool/', '--authentication-file', '/builds/relengapi.tok', 'fetch', '-m', '/builds/slave/test/build/tests/config/tooltool-manifests/macosx64/releng.manifest', '-o', '-c', '/builds/tooltool_cache'] with output_timeout 600 04:06:29 INFO - INFO - File macosx64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache 04:06:29 INFO - Return code: 0 04:06:29 INFO - Chmoding /builds/slave/test/build/macosx64-minidump_stackwalk to 0755 04:06:29 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir 04:06:29 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir 04:06:29 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/macosx64-minidump_stackwalk 04:06:29 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir 04:06:29 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--branchName', 'Fx-Team', '--suite', 'g4-e10s', '--executablePath', '/builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.crashreporter-symbols.zip', '--title', 't-yosemite-r7-0085', '--webServer', 'localhost', '--log-tbpl-level=debug', '--log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-e10s_errorsummary.log', '--log-raw=/builds/slave/test/build/blobber_upload_dir/g4-e10s_raw.log'] in /builds/slave/test/build 04:06:29 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/tests/talos/talos/run_tests.py --branchName Fx-Team --suite g4-e10s --executablePath /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox --symbolsPath https://queue.taskcluster.net/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.crashreporter-symbols.zip --title t-yosemite-r7-0085 --webServer localhost --log-tbpl-level=debug --log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-e10s_errorsummary.log --log-raw=/builds/slave/test/build/blobber_upload_dir/g4-e10s_raw.log 04:06:29 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.60BmflXbZZ/Render', 04:06:29 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 04:06:29 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 04:06:29 INFO - 'HOME': '/Users/cltbld', 04:06:29 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 04:06:29 INFO - 'LOGNAME': 'cltbld', 04:06:29 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 04:06:29 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/macosx64-minidump_stackwalk', 04:06:29 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:06:29 INFO - 'MOZ_NO_REMOTE': '1', 04:06:29 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 04:06:29 INFO - 'NO_EM_RESTART': '1', 04:06:29 INFO - 'PAGER': '/bin/cat', 04:06:29 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 04:06:29 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:06:29 INFO - 'PWD': '/builds/slave/test', 04:06:29 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 04:06:29 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 04:06:29 INFO - 'SHELL': '/bin/bash', 04:06:29 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.MN4hGYEesj/Listeners', 04:06:29 INFO - 'TMPDIR': '/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/', 04:06:29 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 04:06:29 INFO - 'USER': 'cltbld', 04:06:29 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 04:06:29 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 04:06:29 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:06:29 INFO - 'XPC_FLAGS': '0x0', 04:06:29 INFO - 'XPC_SERVICE_NAME': '0', 04:06:29 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0:0'} 04:06:29 INFO - Calling ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--branchName', 'Fx-Team', '--suite', 'g4-e10s', '--executablePath', '/builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.crashreporter-symbols.zip', '--title', 't-yosemite-r7-0085', '--webServer', 'localhost', '--log-tbpl-level=debug', '--log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-e10s_errorsummary.log', '--log-raw=/builds/slave/test/build/blobber_upload_dir/g4-e10s_raw.log'] with output_timeout 3600 04:06:29 INFO - mozversion application_buildid: 20160711012926 04:06:29 INFO - mozversion application_changeset: 76d556ef9180969ee8d690ed069732faded934a2 04:06:29 INFO - mozversion application_display_name: Nightly 04:06:29 INFO - mozversion application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384} 04:06:29 INFO - mozversion application_name: Firefox 04:06:29 INFO - mozversion application_remotingname: firefox 04:06:29 INFO - mozversion application_repository: https://hg.mozilla.org/integration/fx-team 04:06:29 INFO - mozversion application_vendor: Mozilla 04:06:29 INFO - mozversion application_version: 50.0a1 04:06:29 INFO - mozversion platform_buildid: 20160711012926 04:06:29 INFO - mozversion platform_changeset: 76d556ef9180969ee8d690ed069732faded934a2 04:06:29 INFO - mozversion platform_repository: https://hg.mozilla.org/integration/fx-team 04:06:29 INFO - mozversion platform_version: 50.0a1 04:06:29 INFO - using testdate: 1468235189 04:06:29 INFO - actual date: 1468235189 04:06:29 INFO - starting webserver on 'localhost:49274' 04:06:29 INFO - SUITE-START | Running 1 tests 04:06:29 INFO - TEST-START | basic_compositor_video 04:06:29 INFO - operating with platform_type : mac_ 04:06:29 INFO - Initialising browser for basic_compositor_video test... 04:06:29 INFO - TEST-INFO | started process 1649 (/builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/tmphu0U97/profile http://localhost:49274/getInfo.html) 04:06:32 INFO - PROCESS | 1649 | __metrics Screen width/height:1600/1200 04:06:32 INFO - PROCESS | 1649 | colorDepth:24 04:06:32 INFO - PROCESS | 1649 | Browser inner width/height: 1024/689 04:06:32 INFO - PROCESS | 1649 | __metrics 04:06:32 ERROR - PROCESS | 1649 | JavaScript error: chrome://browser/content/tabbrowser.xml, line 2964: TypeError: this.tabs is undefined 04:06:33 INFO - TEST-INFO | 1649: exit 0 04:06:33 INFO - Browser initialized. 04:06:33 INFO - Running cycle 1/1 for basic_compositor_video test... 04:06:33 INFO - TEST-INFO | started process 1652 (/builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/tmphu0U97/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/video/video.manifest.develop -tpchrome -tpnoisy -tpcycles 1 -tppagecycles 12) 04:06:45 INFO - PROCESS | 1652 | RSS: Main: 252628992 04:06:45 INFO - PROCESS | 1652 | 04:07:35 INFO - PROCESS | 1652 | 1468235255319 addons.productaddons ERROR Request failed certificate checks: [Exception... "SSL is required and URI scheme is not https." nsresult: "0x8000ffff (NS_ERROR_UNEXPECTED)" location: "JS frame :: resource://gre/modules/CertUtils.jsm :: checkCert :: line 145" data: no] 04:07:48 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_fullscreen_startup = 22.908664122137402 ms/frame 04:07:48 INFO - PROCESS | 1652 | 04:07:48 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_fullscreen_inclip = 19.612401960784315 ms/frame 04:07:48 INFO - PROCESS | 1652 | 04:07:48 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1_startup = 5.71695238095238 ms/frame 04:07:48 INFO - PROCESS | 1652 | 04:07:48 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1_inclip = 5.183380829015544 ms/frame 04:07:48 INFO - PROCESS | 1652 | 04:07:48 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1.1_startup = 5.4748448905109495 ms/frame 04:07:48 INFO - PROCESS | 1652 | 04:07:48 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 5.635112676056338 ms/frame 04:07:48 INFO - PROCESS | 1652 | 04:07:48 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_2_startup = 7.713547557840611 ms/frame 04:07:48 INFO - PROCESS | 1652 | 04:07:48 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_2_inclip = 7.782743190661482 ms/frame 04:07:48 INFO - PROCESS | 1652 | 04:07:48 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_fullscreen_startup = 10.652180851063832 ms/frame 04:07:48 INFO - PROCESS | 1652 | 04:07:48 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_fullscreen_inclip = 9.530809523809513 ms/frame 04:07:48 INFO - PROCESS | 1652 | 04:07:48 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1_startup = 4.666321928460341 ms/frame 04:07:48 INFO - PROCESS | 1652 | 04:07:48 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1_inclip = 4.0916768916155455 ms/frame 04:07:48 INFO - PROCESS | 1652 | 04:07:48 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.519118975903614 ms/frame 04:07:48 INFO - PROCESS | 1652 | 04:07:48 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.58973623853211 ms/frame 04:07:48 INFO - PROCESS | 1652 | 04:07:48 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_2_startup = 4.839870967741938 ms/frame 04:07:48 INFO - PROCESS | 1652 | 04:07:48 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_2_inclip = 4.869671532846709 ms/frame 04:07:48 INFO - PROCESS | 1652 | 04:07:48 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_fullscreen_startup = 69.7962790697674 ms/frame 04:07:48 INFO - PROCESS | 1652 | 04:07:48 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_fullscreen_inclip = 62.52187499999991 ms/frame 04:07:48 INFO - PROCESS | 1652 | 04:07:48 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1_startup = 48.390564516128975 ms/frame 04:07:48 INFO - PROCESS | 1652 | 04:07:48 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1_inclip = 37.056944444444525 ms/frame 04:07:48 INFO - PROCESS | 1652 | 04:07:48 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 43.49340579710153 ms/frame 04:07:48 INFO - PROCESS | 1652 | 04:07:48 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 40.83897959183675 ms/frame 04:07:48 INFO - PROCESS | 1652 | 04:07:48 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_2_startup = 42.867928571428536 ms/frame 04:07:48 INFO - PROCESS | 1652 | 04:07:48 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_2_inclip = 44.443777777777804 ms/frame 04:07:48 INFO - PROCESS | 1652 | 04:07:48 INFO - PROCESS | 1652 | Cycle 1(1): loaded http://localhost:49274/tests/video/video_playback.html (next: http://localhost:49274/tests/video/video_playback.html) 04:07:49 INFO - PROCESS | 1652 | RSS: Main: 275795968 04:07:49 INFO - PROCESS | 1652 | 04:08:51 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_fullscreen_startup = 20.558321917808218 ms/frame 04:08:51 INFO - PROCESS | 1652 | 04:08:51 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_fullscreen_inclip = 19.61686274509804 ms/frame 04:08:51 INFO - PROCESS | 1652 | 04:08:51 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1_startup = 5.599365671641792 ms/frame 04:08:51 INFO - PROCESS | 1652 | 04:08:51 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1_inclip = 4.917714987714988 ms/frame 04:08:51 INFO - PROCESS | 1652 | 04:08:51 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1.1_startup = 5.367119856887298 ms/frame 04:08:51 INFO - PROCESS | 1652 | 04:08:51 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 5.1024744897959184 ms/frame 04:08:51 INFO - PROCESS | 1652 | 04:08:51 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_2_startup = 7.371793611793611 ms/frame 04:08:51 INFO - PROCESS | 1652 | 04:08:51 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_2_inclip = 7.876929133858274 ms/frame 04:08:51 INFO - PROCESS | 1652 | 04:08:51 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_fullscreen_startup = 10.802949640287775 ms/frame 04:08:51 INFO - PROCESS | 1652 | 04:08:51 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_fullscreen_inclip = 9.621538461538474 ms/frame 04:08:51 INFO - PROCESS | 1652 | 04:08:51 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1_startup = 4.762293650793649 ms/frame 04:08:51 INFO - PROCESS | 1652 | 04:08:51 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1_inclip = 4.196215932914049 ms/frame 04:08:51 INFO - PROCESS | 1652 | 04:08:51 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.735394321766559 ms/frame 04:08:51 INFO - PROCESS | 1652 | 04:08:51 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.8089302884615375 ms/frame 04:08:51 INFO - PROCESS | 1652 | 04:08:51 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_2_startup = 4.887092833876226 ms/frame 04:08:51 INFO - PROCESS | 1652 | 04:08:51 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_2_inclip = 5.002037499999988 ms/frame 04:08:51 INFO - PROCESS | 1652 | 04:08:51 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_fullscreen_startup = 66.68799999999997 ms/frame 04:08:51 INFO - PROCESS | 1652 | 04:08:51 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_fullscreen_inclip = 64.53258064516136 ms/frame 04:08:51 INFO - PROCESS | 1652 | 04:08:51 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1_startup = 41.68597222222232 ms/frame 04:08:51 INFO - PROCESS | 1652 | 04:08:51 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1_inclip = 46.53883720930229 ms/frame 04:08:51 INFO - PROCESS | 1652 | 04:08:51 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 48.396129032258024 ms/frame 04:08:51 INFO - PROCESS | 1652 | 04:08:51 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 50.007875000000055 ms/frame 04:08:51 INFO - PROCESS | 1652 | 04:08:51 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_2_startup = 45.46333333333336 ms/frame 04:08:51 INFO - PROCESS | 1652 | 04:08:51 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_2_inclip = 40.8324489795917 ms/frame 04:08:51 INFO - PROCESS | 1652 | 04:08:51 INFO - PROCESS | 1652 | Cycle 1(2): loaded http://localhost:49274/tests/video/video_playback.html (next: http://localhost:49274/tests/video/video_playback.html) 04:08:52 INFO - PROCESS | 1652 | RSS: Main: 278151168 04:08:52 INFO - PROCESS | 1652 | 04:09:54 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_fullscreen_startup = 20.703862068965517 ms/frame 04:09:54 INFO - PROCESS | 1652 | 04:09:54 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_fullscreen_inclip = 20.416785714285712 ms/frame 04:09:54 INFO - PROCESS | 1652 | 04:09:54 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1_startup = 5.78553949903661 ms/frame 04:09:54 INFO - PROCESS | 1652 | 04:09:54 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1_inclip = 4.787236842105265 ms/frame 04:09:54 INFO - PROCESS | 1652 | 04:09:54 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1.1_startup = 5.629727954971858 ms/frame 04:09:54 INFO - PROCESS | 1652 | 04:09:54 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 5.378400537634407 ms/frame 04:09:54 INFO - PROCESS | 1652 | 04:09:54 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_2_startup = 8.02723262032086 ms/frame 04:09:54 INFO - PROCESS | 1652 | 04:09:54 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_2_inclip = 8.067338709677408 ms/frame 04:09:54 INFO - PROCESS | 1652 | 04:09:54 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_fullscreen_startup = 10.569137323943655 ms/frame 04:09:54 INFO - PROCESS | 1652 | 04:09:54 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_fullscreen_inclip = 9.485023696682465 ms/frame 04:09:54 INFO - PROCESS | 1652 | 04:09:54 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1_startup = 4.801568 ms/frame 04:09:54 INFO - PROCESS | 1652 | 04:09:54 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1_inclip = 4.03583669354839 ms/frame 04:09:54 INFO - PROCESS | 1652 | 04:09:54 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.769475357710646 ms/frame 04:09:54 INFO - PROCESS | 1652 | 04:09:54 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.7300472813238885 ms/frame 04:09:54 INFO - PROCESS | 1652 | 04:09:54 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_2_startup = 5.181658031088084 ms/frame 04:09:54 INFO - PROCESS | 1652 | 04:09:54 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_2_inclip = 4.916130221130234 ms/frame 04:09:54 INFO - PROCESS | 1652 | 04:09:54 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_fullscreen_startup = 73.17951219512196 ms/frame 04:09:54 INFO - PROCESS | 1652 | 04:09:54 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_fullscreen_inclip = 66.68400000000014 ms/frame 04:09:54 INFO - PROCESS | 1652 | 04:09:54 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1_startup = 47.635079365079285 ms/frame 04:09:54 INFO - PROCESS | 1652 | 04:09:54 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1_inclip = 44.4514444444445 ms/frame 04:09:54 INFO - PROCESS | 1652 | 04:09:54 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 42.86707142857142 ms/frame 04:09:54 INFO - PROCESS | 1652 | 04:09:54 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 45.455681818181716 ms/frame 04:09:54 INFO - PROCESS | 1652 | 04:09:54 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_2_startup = 47.63761904761902 ms/frame 04:09:54 INFO - PROCESS | 1652 | 04:09:54 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_2_inclip = 41.70770833333336 ms/frame 04:09:54 INFO - PROCESS | 1652 | 04:09:54 INFO - PROCESS | 1652 | Cycle 1(3): loaded http://localhost:49274/tests/video/video_playback.html (next: http://localhost:49274/tests/video/video_playback.html) 04:09:55 INFO - PROCESS | 1652 | RSS: Main: 288722944 04:09:55 INFO - PROCESS | 1652 | 04:10:58 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_fullscreen_startup = 20.279831081081085 ms/frame 04:10:58 INFO - PROCESS | 1652 | 04:10:58 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_fullscreen_inclip = 20.0075 ms/frame 04:10:58 INFO - PROCESS | 1652 | 04:10:58 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1_startup = 5.714933333333334 ms/frame 04:10:58 INFO - PROCESS | 1652 | 04:10:58 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1_inclip = 4.7535391923990495 ms/frame 04:10:58 INFO - PROCESS | 1652 | 04:10:58 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1.1_startup = 5.116933560477004 ms/frame 04:10:58 INFO - PROCESS | 1652 | 04:10:58 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 5.2230026109660574 ms/frame 04:10:58 INFO - PROCESS | 1652 | 04:10:58 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_2_startup = 7.856963350785342 ms/frame 04:10:58 INFO - PROCESS | 1652 | 04:10:58 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_2_inclip = 7.6669157088122555 ms/frame 04:10:58 INFO - PROCESS | 1652 | 04:10:58 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_fullscreen_startup = 10.95204379562044 ms/frame 04:10:58 INFO - PROCESS | 1652 | 04:10:58 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_fullscreen_inclip = 9.812352941176458 ms/frame 04:10:58 INFO - PROCESS | 1652 | 04:10:58 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1_startup = 4.967748344370862 ms/frame 04:10:58 INFO - PROCESS | 1652 | 04:10:58 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1_inclip = 4.330119047619054 ms/frame 04:10:58 INFO - PROCESS | 1652 | 04:10:58 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.92133606557377 ms/frame 04:10:58 INFO - PROCESS | 1652 | 04:10:58 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.810468749999997 ms/frame 04:10:58 INFO - PROCESS | 1652 | 04:10:58 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_2_startup = 5.588221601489758 ms/frame 04:10:58 INFO - PROCESS | 1652 | 04:10:58 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_2_inclip = 5.397479784366568 ms/frame 04:10:58 INFO - PROCESS | 1652 | 04:10:58 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_fullscreen_startup = 63.846808510638205 ms/frame 04:10:58 INFO - PROCESS | 1652 | 04:10:58 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_fullscreen_inclip = 62.5065625000002 ms/frame 04:10:58 INFO - PROCESS | 1652 | 04:10:58 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1_startup = 44.78007462686566 ms/frame 04:10:58 INFO - PROCESS | 1652 | 04:10:58 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1_inclip = 46.520465116279176 ms/frame 04:10:58 INFO - PROCESS | 1652 | 04:10:58 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 46.170230769230805 ms/frame 04:10:58 INFO - PROCESS | 1652 | 04:10:58 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 47.62190476190482 ms/frame 04:10:58 INFO - PROCESS | 1652 | 04:10:58 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_2_startup = 48.394354838709745 ms/frame 04:10:58 INFO - PROCESS | 1652 | 04:10:58 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_2_inclip = 46.55976744186046 ms/frame 04:10:58 INFO - PROCESS | 1652 | 04:10:58 INFO - PROCESS | 1652 | Cycle 1(4): loaded http://localhost:49274/tests/video/video_playback.html (next: http://localhost:49274/tests/video/video_playback.html) 04:10:58 INFO - PROCESS | 1652 | RSS: Main: 289157120 04:10:58 INFO - PROCESS | 1652 | 04:12:01 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_fullscreen_startup = 21.58679856115108 ms/frame 04:12:01 INFO - PROCESS | 1652 | 04:12:01 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_fullscreen_inclip = 19.426601941747574 ms/frame 04:12:01 INFO - PROCESS | 1652 | 04:12:01 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1_startup = 5.780693641618499 ms/frame 04:12:01 INFO - PROCESS | 1652 | 04:12:01 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1_inclip = 5.211210937499999 ms/frame 04:12:01 INFO - PROCESS | 1652 | 04:12:01 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1.1_startup = 5.566846011131723 ms/frame 04:12:01 INFO - PROCESS | 1652 | 04:12:01 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 5.439062500000002 ms/frame 04:12:01 INFO - PROCESS | 1652 | 04:12:01 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_2_startup = 7.178373205741625 ms/frame 04:12:01 INFO - PROCESS | 1652 | 04:12:01 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_2_inclip = 7.968107569721112 ms/frame 04:12:01 INFO - PROCESS | 1652 | 04:12:01 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_fullscreen_startup = 11.051360294117652 ms/frame 04:12:01 INFO - PROCESS | 1652 | 04:12:01 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_fullscreen_inclip = 9.571746411483248 ms/frame 04:12:01 INFO - PROCESS | 1652 | 04:12:01 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1_startup = 4.935205592105262 ms/frame 04:12:01 INFO - PROCESS | 1652 | 04:12:01 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1_inclip = 4.249214437367306 ms/frame 04:12:01 INFO - PROCESS | 1652 | 04:12:01 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.785988835725681 ms/frame 04:12:01 INFO - PROCESS | 1652 | 04:12:01 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.914840294840286 ms/frame 04:12:01 INFO - PROCESS | 1652 | 04:12:01 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_2_startup = 5.000866666666673 ms/frame 04:12:01 INFO - PROCESS | 1652 | 04:12:01 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_2_inclip = 4.963200992555827 ms/frame 04:12:01 INFO - PROCESS | 1652 | 04:12:01 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_fullscreen_startup = 71.45273809523808 ms/frame 04:12:01 INFO - PROCESS | 1652 | 04:12:01 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_fullscreen_inclip = 66.68299999999994 ms/frame 04:12:01 INFO - PROCESS | 1652 | 04:12:01 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1_startup = 49.186885245901664 ms/frame 04:12:01 INFO - PROCESS | 1652 | 04:12:01 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1_inclip = 47.64642857142861 ms/frame 04:12:01 INFO - PROCESS | 1652 | 04:12:01 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 50.86000000000009 ms/frame 04:12:01 INFO - PROCESS | 1652 | 04:12:01 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 42.57170212765948 ms/frame 04:12:01 INFO - PROCESS | 1652 | 04:12:01 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_2_startup = 44.125 ms/frame 04:12:01 INFO - PROCESS | 1652 | 04:12:01 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_2_inclip = 43.4906521739132 ms/frame 04:12:01 INFO - PROCESS | 1652 | 04:12:01 INFO - PROCESS | 1652 | Cycle 1(5): loaded http://localhost:49274/tests/video/video_playback.html (next: http://localhost:49274/tests/video/video_playback.html) 04:12:01 INFO - PROCESS | 1652 | RSS: Main: 287752192 04:12:01 INFO - PROCESS | 1652 | 04:13:04 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_fullscreen_startup = 23.262248062015505 ms/frame 04:13:04 INFO - PROCESS | 1652 | 04:13:04 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_fullscreen_inclip = 19.420922330097085 ms/frame 04:13:04 INFO - PROCESS | 1652 | 04:13:04 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1_startup = 5.726851145038166 ms/frame 04:13:04 INFO - PROCESS | 1652 | 04:13:04 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1_inclip = 4.85742718446602 ms/frame 04:13:04 INFO - PROCESS | 1652 | 04:13:04 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1.1_startup = 5.183721934369602 ms/frame 04:13:04 INFO - PROCESS | 1652 | 04:13:04 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 5.196987012987013 ms/frame 04:13:04 INFO - PROCESS | 1652 | 04:13:04 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_2_startup = 8.175803814713893 ms/frame 04:13:04 INFO - PROCESS | 1652 | 04:13:04 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_2_inclip = 7.549886792452835 ms/frame 04:13:04 INFO - PROCESS | 1652 | 04:13:04 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_fullscreen_startup = 10.95135036496351 ms/frame 04:13:04 INFO - PROCESS | 1652 | 04:13:04 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_fullscreen_inclip = 9.525547619047627 ms/frame 04:13:04 INFO - PROCESS | 1652 | 04:13:04 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1_startup = 4.696384976525824 ms/frame 04:13:04 INFO - PROCESS | 1652 | 04:13:04 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1_inclip = 4.151151452282157 ms/frame 04:13:04 INFO - PROCESS | 1652 | 04:13:04 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.816059390048152 ms/frame 04:13:04 INFO - PROCESS | 1652 | 04:13:04 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.867080291970809 ms/frame 04:13:04 INFO - PROCESS | 1652 | 04:13:04 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_2_startup = 5.112197614991483 ms/frame 04:13:04 INFO - PROCESS | 1652 | 04:13:04 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_2_inclip = 5.01416040100251 ms/frame 04:13:04 INFO - PROCESS | 1652 | 04:13:04 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_fullscreen_startup = 68.20227272727276 ms/frame 04:13:04 INFO - PROCESS | 1652 | 04:13:04 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_fullscreen_inclip = 68.98051724137949 ms/frame 04:13:04 INFO - PROCESS | 1652 | 04:13:04 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1_startup = 47.63547619047613 ms/frame 04:13:04 INFO - PROCESS | 1652 | 04:13:04 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1_inclip = 40.00830000000002 ms/frame 04:13:04 INFO - PROCESS | 1652 | 04:13:04 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 42.25457746478869 ms/frame 04:13:04 INFO - PROCESS | 1652 | 04:13:04 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 44.455777777777826 ms/frame 04:13:04 INFO - PROCESS | 1652 | 04:13:04 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_2_startup = 46.164076923076934 ms/frame 04:13:04 INFO - PROCESS | 1652 | 04:13:04 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_2_inclip = 43.5393478260869 ms/frame 04:13:04 INFO - PROCESS | 1652 | 04:13:04 INFO - PROCESS | 1652 | Cycle 1(6): loaded http://localhost:49274/tests/video/video_playback.html (next: http://localhost:49274/tests/video/video_playback.html) 04:13:05 INFO - PROCESS | 1652 | RSS: Main: 289079296 04:13:05 INFO - PROCESS | 1652 | 04:14:07 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_fullscreen_startup = 22.394626865671643 ms/frame 04:14:07 INFO - PROCESS | 1652 | 04:14:07 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_fullscreen_inclip = 20.21272727272727 ms/frame 04:14:07 INFO - PROCESS | 1652 | 04:14:07 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1_startup = 5.693548387096774 ms/frame 04:14:07 INFO - PROCESS | 1652 | 04:14:07 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1_inclip = 5.364048257372657 ms/frame 04:14:07 INFO - PROCESS | 1652 | 04:14:07 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1.1_startup = 5.474589416058392 ms/frame 04:14:07 INFO - PROCESS | 1652 | 04:14:07 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 5.450204359673026 ms/frame 04:14:07 INFO - PROCESS | 1652 | 04:14:07 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_2_startup = 7.835913838120101 ms/frame 04:14:07 INFO - PROCESS | 1652 | 04:14:07 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_2_inclip = 7.783599221789891 ms/frame 04:14:07 INFO - PROCESS | 1652 | 04:14:07 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_fullscreen_startup = 10.533245614035083 ms/frame 04:14:07 INFO - PROCESS | 1652 | 04:14:07 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_fullscreen_inclip = 9.304186046511635 ms/frame 04:14:07 INFO - PROCESS | 1652 | 04:14:07 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1_startup = 4.918967213114754 ms/frame 04:14:07 INFO - PROCESS | 1652 | 04:14:07 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1_inclip = 4.378796498905909 ms/frame 04:14:07 INFO - PROCESS | 1652 | 04:14:07 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.532877643504525 ms/frame 04:14:07 INFO - PROCESS | 1652 | 04:14:07 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.4554899777283 ms/frame 04:14:07 INFO - PROCESS | 1652 | 04:14:07 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_2_startup = 5.000466666666664 ms/frame 04:14:07 INFO - PROCESS | 1652 | 04:14:07 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_2_inclip = 5.039886649874053 ms/frame 04:14:07 INFO - PROCESS | 1652 | 04:14:07 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_fullscreen_startup = 76.94307692307709 ms/frame 04:14:07 INFO - PROCESS | 1652 | 04:14:07 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_fullscreen_inclip = 62.535468749999836 ms/frame 04:14:07 INFO - PROCESS | 1652 | 04:14:07 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1_startup = 50.00616666666671 ms/frame 04:14:07 INFO - PROCESS | 1652 | 04:14:07 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1_inclip = 43.5 ms/frame 04:14:07 INFO - PROCESS | 1652 | 04:14:07 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 48.4021774193548 ms/frame 04:14:07 INFO - PROCESS | 1652 | 04:14:07 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 43.503369565217525 ms/frame 04:14:07 INFO - PROCESS | 1652 | 04:14:07 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_2_startup = 49.1909836065574 ms/frame 04:14:07 INFO - PROCESS | 1652 | 04:14:07 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_2_inclip = 46.54674418604639 ms/frame 04:14:07 INFO - PROCESS | 1652 | 04:14:07 INFO - PROCESS | 1652 | Cycle 1(7): loaded http://localhost:49274/tests/video/video_playback.html (next: http://localhost:49274/tests/video/video_playback.html) 04:14:08 INFO - PROCESS | 1652 | RSS: Main: 288583680 04:14:08 INFO - PROCESS | 1652 | 04:15:10 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_fullscreen_startup = 20.556027397260277 ms/frame 04:15:10 INFO - PROCESS | 1652 | 04:15:10 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_fullscreen_inclip = 20.625206185567016 ms/frame 04:15:10 INFO - PROCESS | 1652 | 04:15:10 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1_startup = 5.838686770428014 ms/frame 04:15:10 INFO - PROCESS | 1652 | 04:15:10 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1_inclip = 5.142699228791774 ms/frame 04:15:10 INFO - PROCESS | 1652 | 04:15:10 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1.1_startup = 5.769750000000001 ms/frame 04:15:10 INFO - PROCESS | 1652 | 04:15:10 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 5.437472826086956 ms/frame 04:15:10 INFO - PROCESS | 1652 | 04:15:10 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_2_startup = 7.919907651715036 ms/frame 04:15:10 INFO - PROCESS | 1652 | 04:15:10 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_2_inclip = 7.329505494505501 ms/frame 04:15:10 INFO - PROCESS | 1652 | 04:15:10 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_fullscreen_startup = 10.312216494845359 ms/frame 04:15:10 INFO - PROCESS | 1652 | 04:15:10 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_fullscreen_inclip = 9.667971014492755 ms/frame 04:15:10 INFO - PROCESS | 1652 | 04:15:10 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1_startup = 4.566765601217653 ms/frame 04:15:10 INFO - PROCESS | 1652 | 04:15:10 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1_inclip = 4.177275574112737 ms/frame 04:15:10 INFO - PROCESS | 1652 | 04:15:10 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.622681047765792 ms/frame 04:15:10 INFO - PROCESS | 1652 | 04:15:10 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.4653236607142945 ms/frame 04:15:10 INFO - PROCESS | 1652 | 04:15:10 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_2_startup = 5.192102076124561 ms/frame 04:15:10 INFO - PROCESS | 1652 | 04:15:10 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_2_inclip = 5.0644177215189865 ms/frame 04:15:10 INFO - PROCESS | 1652 | 04:15:10 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_fullscreen_startup = 69.78162790697675 ms/frame 04:15:10 INFO - PROCESS | 1652 | 04:15:10 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_fullscreen_inclip = 71.42624999999991 ms/frame 04:15:10 INFO - PROCESS | 1652 | 04:15:10 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1_startup = 45.463863636363605 ms/frame 04:15:10 INFO - PROCESS | 1652 | 04:15:10 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1_inclip = 40.01899999999994 ms/frame 04:15:10 INFO - PROCESS | 1652 | 04:15:10 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 48.40991935483872 ms/frame 04:15:10 INFO - PROCESS | 1652 | 04:15:10 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 44.46344444444451 ms/frame 04:15:10 INFO - PROCESS | 1652 | 04:15:10 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_2_startup = 45.46901515151518 ms/frame 04:15:10 INFO - PROCESS | 1652 | 04:15:10 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_2_inclip = 43.50967391304347 ms/frame 04:15:10 INFO - PROCESS | 1652 | 04:15:10 INFO - PROCESS | 1652 | Cycle 1(8): loaded http://localhost:49274/tests/video/video_playback.html (next: http://localhost:49274/tests/video/video_playback.html) 04:15:11 INFO - PROCESS | 1652 | RSS: Main: 287985664 04:15:11 INFO - PROCESS | 1652 | 04:16:14 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_fullscreen_startup = 20.9836013986014 ms/frame 04:16:14 INFO - PROCESS | 1652 | 04:16:14 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_fullscreen_inclip = 20.446785714285717 ms/frame 04:16:14 INFO - PROCESS | 1652 | 04:16:14 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1_startup = 5.584934944237918 ms/frame 04:16:14 INFO - PROCESS | 1652 | 04:16:14 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1_inclip = 4.90469362745098 ms/frame 04:16:14 INFO - PROCESS | 1652 | 04:16:14 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1.1_startup = 5.7177333333333324 ms/frame 04:16:14 INFO - PROCESS | 1652 | 04:16:14 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 5.349732620320854 ms/frame 04:16:14 INFO - PROCESS | 1652 | 04:16:14 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_2_startup = 7.179545454545453 ms/frame 04:16:14 INFO - PROCESS | 1652 | 04:16:14 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_2_inclip = 7.666417624521078 ms/frame 04:16:14 INFO - PROCESS | 1652 | 04:16:14 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_fullscreen_startup = 11.03314338235294 ms/frame 04:16:14 INFO - PROCESS | 1652 | 04:16:14 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_fullscreen_inclip = 9.397065727699534 ms/frame 04:16:14 INFO - PROCESS | 1652 | 04:16:14 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1_startup = 4.6898984375 ms/frame 04:16:14 INFO - PROCESS | 1652 | 04:16:14 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1_inclip = 4.140693581780542 ms/frame 04:16:14 INFO - PROCESS | 1652 | 04:16:14 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.637766615146829 ms/frame 04:16:14 INFO - PROCESS | 1652 | 04:16:14 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.763702380952392 ms/frame 04:16:14 INFO - PROCESS | 1652 | 04:16:14 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_2_startup = 4.832801932367147 ms/frame 04:16:14 INFO - PROCESS | 1652 | 04:16:14 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_2_inclip = 4.730401891252953 ms/frame 04:16:14 INFO - PROCESS | 1652 | 04:16:14 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_fullscreen_startup = 76.93256410256399 ms/frame 04:16:14 INFO - PROCESS | 1652 | 04:16:14 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_fullscreen_inclip = 71.43482142857154 ms/frame 04:16:14 INFO - PROCESS | 1652 | 04:16:14 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1_startup = 42.87221428571429 ms/frame 04:16:14 INFO - PROCESS | 1652 | 04:16:14 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1_inclip = 40.010899999999964 ms/frame 04:16:14 INFO - PROCESS | 1652 | 04:16:14 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 46.161384615384584 ms/frame 04:16:14 INFO - PROCESS | 1652 | 04:16:14 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 44.4633333333333 ms/frame 04:16:14 INFO - PROCESS | 1652 | 04:16:14 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_2_startup = 50.86728813559319 ms/frame 04:16:14 INFO - PROCESS | 1652 | 04:16:14 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_2_inclip = 44.46311111111103 ms/frame 04:16:14 INFO - PROCESS | 1652 | 04:16:14 INFO - PROCESS | 1652 | Cycle 1(9): loaded http://localhost:49274/tests/video/video_playback.html (next: http://localhost:49274/tests/video/video_playback.html) 04:16:14 INFO - PROCESS | 1652 | RSS: Main: 289439744 04:16:14 INFO - PROCESS | 1652 | 04:17:17 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_fullscreen_startup = 21.134894366197184 ms/frame 04:17:17 INFO - PROCESS | 1652 | 04:17:17 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_fullscreen_inclip = 21.752717391304344 ms/frame 04:17:17 INFO - PROCESS | 1652 | 04:17:17 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1_startup = 5.640216165413534 ms/frame 04:17:17 INFO - PROCESS | 1652 | 04:17:17 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1_inclip = 4.855097087378639 ms/frame 04:17:17 INFO - PROCESS | 1652 | 04:17:17 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1.1_startup = 5.758032629558544 ms/frame 04:17:17 INFO - PROCESS | 1652 | 04:17:17 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 6.026551204819273 ms/frame 04:17:17 INFO - PROCESS | 1652 | 04:17:17 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_2_startup = 7.959721485411147 ms/frame 04:17:17 INFO - PROCESS | 1652 | 04:17:17 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_2_inclip = 7.816171874999995 ms/frame 04:17:17 INFO - PROCESS | 1652 | 04:17:17 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_fullscreen_startup = 10.832472924187718 ms/frame 04:17:17 INFO - PROCESS | 1652 | 04:17:17 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_fullscreen_inclip = 9.812205882352952 ms/frame 04:17:17 INFO - PROCESS | 1652 | 04:17:17 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1_startup = 4.943607907742993 ms/frame 04:17:17 INFO - PROCESS | 1652 | 04:17:17 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1_inclip = 4.414834437086097 ms/frame 04:17:17 INFO - PROCESS | 1652 | 04:17:17 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.894567699836872 ms/frame 04:17:17 INFO - PROCESS | 1652 | 04:17:17 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.878146341463399 ms/frame 04:17:17 INFO - PROCESS | 1652 | 04:17:17 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_2_startup = 5.173172413793107 ms/frame 04:17:17 INFO - PROCESS | 1652 | 04:17:17 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_2_inclip = 5.168901808785525 ms/frame 04:17:17 INFO - PROCESS | 1652 | 04:17:17 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_fullscreen_startup = 73.2020731707318 ms/frame 04:17:17 INFO - PROCESS | 1652 | 04:17:17 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_fullscreen_inclip = 76.92961538461532 ms/frame 04:17:17 INFO - PROCESS | 1652 | 04:17:17 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1_startup = 45.458333333333336 ms/frame 04:17:17 INFO - PROCESS | 1652 | 04:17:17 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1_inclip = 45.46090909090906 ms/frame 04:17:17 INFO - PROCESS | 1652 | 04:17:17 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 50.00766666666665 ms/frame 04:17:17 INFO - PROCESS | 1652 | 04:17:17 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 40.82581632653054 ms/frame 04:17:17 INFO - PROCESS | 1652 | 04:17:17 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_2_startup = 45.47143939393948 ms/frame 04:17:17 INFO - PROCESS | 1652 | 04:17:17 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_2_inclip = 44.464111111110995 ms/frame 04:17:17 INFO - PROCESS | 1652 | 04:17:17 INFO - PROCESS | 1652 | Cycle 1(10): loaded http://localhost:49274/tests/video/video_playback.html (next: http://localhost:49274/tests/video/video_playback.html) 04:17:18 INFO - PROCESS | 1652 | RSS: Main: 287981568 04:17:18 INFO - PROCESS | 1652 | 04:18:20 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_fullscreen_startup = 21.44407142857143 ms/frame 04:18:20 INFO - PROCESS | 1652 | 04:18:20 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_fullscreen_inclip = 19.807970297029705 ms/frame 04:18:20 INFO - PROCESS | 1652 | 04:18:20 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1_startup = 5.800888030888032 ms/frame 04:18:20 INFO - PROCESS | 1652 | 04:18:20 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1_inclip = 4.97691542288557 ms/frame 04:18:20 INFO - PROCESS | 1652 | 04:18:20 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1.1_startup = 5.140556506849316 ms/frame 04:18:20 INFO - PROCESS | 1652 | 04:18:20 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 5.33717333333333 ms/frame 04:18:20 INFO - PROCESS | 1652 | 04:18:20 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_2_startup = 8.048632707774802 ms/frame 04:18:20 INFO - PROCESS | 1652 | 04:18:20 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_2_inclip = 7.757829457364343 ms/frame 04:18:20 INFO - PROCESS | 1652 | 04:18:20 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_fullscreen_startup = 10.603727915194344 ms/frame 04:18:20 INFO - PROCESS | 1652 | 04:18:20 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_fullscreen_inclip = 9.902202970297024 ms/frame 04:18:20 INFO - PROCESS | 1652 | 04:18:20 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1_startup = 4.7959584664536745 ms/frame 04:18:20 INFO - PROCESS | 1652 | 04:18:20 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1_inclip = 4.360544662309364 ms/frame 04:18:20 INFO - PROCESS | 1652 | 04:18:20 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.779060509554146 ms/frame 04:18:20 INFO - PROCESS | 1652 | 04:18:20 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.640348027842222 ms/frame 04:18:20 INFO - PROCESS | 1652 | 04:18:20 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_2_startup = 5.211336805555561 ms/frame 04:18:20 INFO - PROCESS | 1652 | 04:18:20 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_2_inclip = 5.143239074550132 ms/frame 04:18:20 INFO - PROCESS | 1652 | 04:18:20 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_fullscreen_startup = 78.96078947368426 ms/frame 04:18:20 INFO - PROCESS | 1652 | 04:18:20 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_fullscreen_inclip = 66.67083333333333 ms/frame 04:18:20 INFO - PROCESS | 1652 | 04:18:20 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1_startup = 46.876171874999955 ms/frame 04:18:20 INFO - PROCESS | 1652 | 04:18:20 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1_inclip = 47.62285714285723 ms/frame 04:18:20 INFO - PROCESS | 1652 | 04:18:20 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 50.01433333333334 ms/frame 04:18:20 INFO - PROCESS | 1652 | 04:18:20 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 44.47177777777785 ms/frame 04:18:20 INFO - PROCESS | 1652 | 04:18:20 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_2_startup = 50.84618644067789 ms/frame 04:18:20 INFO - PROCESS | 1652 | 04:18:20 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_2_inclip = 47.63738095238105 ms/frame 04:18:20 INFO - PROCESS | 1652 | 04:18:20 INFO - PROCESS | 1652 | Cycle 1(11): loaded http://localhost:49274/tests/video/video_playback.html (next: http://localhost:49274/tests/video/video_playback.html) 04:18:21 INFO - PROCESS | 1652 | RSS: Main: 289030144 04:18:21 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_fullscreen_startup = 21.589136690647482 ms/frame 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_fullscreen_inclip = 21.505376344086027 ms/frame 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1_startup = 6.028222891566264 ms/frame 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1_inclip = 5.222624020887731 ms/frame 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1.1_startup = 5.7262404580152655 ms/frame 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 5.350802139037435 ms/frame 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_2_startup = 7.793649350649352 ms/frame 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | testsrc.240p.120fps.mp4_scale_2_inclip = 7.274981818181814 ms/frame 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_fullscreen_startup = 10.565845070422538 ms/frame 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_fullscreen_inclip = 9.76131707317073 ms/frame 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1_startup = 4.952475247524753 ms/frame 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1_inclip = 4.294463519313299 ms/frame 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.718309748427675 ms/frame 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.833321256038636 ms/frame 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_2_startup = 5.12197098976109 ms/frame 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | testsrc.480p.60fps.webm_scale_2_inclip = 4.821192771084333 ms/frame 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_fullscreen_startup = 71.45916666666658 ms/frame 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_fullscreen_inclip = 66.69733333333352 ms/frame 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1_startup = 44.78358208955224 ms/frame 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1_inclip = 37.75132075471711 ms/frame 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 54.56190909090907 ms/frame 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 47.626071428571386 ms/frame 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_2_startup = 47.636111111111184 ms/frame 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | testsrc.1080p.60fps.mp4_scale_2_inclip = 45.47204545454538 ms/frame 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | Cycle 1(12): loaded http://localhost:49274/tests/video/video_playback.html (next: http://localhost:49274/tests/video/video_playback.html) 04:19:23 INFO - PROCESS | 1652 | RSS: Main: 288468992 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | __start_tp_report 04:19:23 INFO - PROCESS | 1652 | _x_x_mozilla_page_load 04:19:23 INFO - PROCESS | 1652 | _x_x_mozilla_page_load_details 04:19:23 INFO - PROCESS | 1652 | |i|pagename|runs| 04:19:23 INFO - PROCESS | 1652 | |0;240p.120fps.mp4_scale_fullscreen_startup;22.908664122137402;20.558321917808218;20.703862068965517;20.279831081081085;21.58679856115108;23.262248062015505;22.394626865671643;20.556027397260277;20.9836013986014;21.134894366197184;21.44407142857143;21.589136690647482 04:19:23 INFO - PROCESS | 1652 | |1;240p.120fps.mp4_scale_fullscreen_inclip;19.612401960784315;19.61686274509804;20.416785714285712;20.0075;19.426601941747574;19.420922330097085;20.21272727272727;20.625206185567016;20.446785714285717;21.752717391304344;19.807970297029705;21.505376344086027 04:19:23 INFO - PROCESS | 1652 | |2;240p.120fps.mp4_scale_1_startup;5.71695238095238;5.599365671641792;5.78553949903661;5.714933333333334;5.780693641618499;5.726851145038166;5.693548387096774;5.838686770428014;5.584934944237918;5.640216165413534;5.800888030888032;6.028222891566264 04:19:23 INFO - PROCESS | 1652 | |3;240p.120fps.mp4_scale_1_inclip;5.183380829015544;4.917714987714988;4.787236842105265;4.7535391923990495;5.211210937499999;4.85742718446602;5.364048257372657;5.142699228791774;4.90469362745098;4.855097087378639;4.97691542288557;5.222624020887731 04:19:23 INFO - PROCESS | 1652 | |4;240p.120fps.mp4_scale_1.1_startup;5.4748448905109495;5.367119856887298;5.629727954971858;5.116933560477004;5.566846011131723;5.183721934369602;5.474589416058392;5.769750000000001;5.7177333333333324;5.758032629558544;5.140556506849316;5.7262404580152655 04:19:23 INFO - PROCESS | 1652 | |5;240p.120fps.mp4_scale_1.1_inclip;5.635112676056338;5.1024744897959184;5.378400537634407;5.2230026109660574;5.439062500000002;5.196987012987013;5.450204359673026;5.437472826086956;5.349732620320854;6.026551204819273;5.33717333333333;5.350802139037435 04:19:23 INFO - PROCESS | 1652 | |6;240p.120fps.mp4_scale_2_startup;7.713547557840611;7.371793611793611;8.02723262032086;7.856963350785342;7.178373205741625;8.175803814713893;7.835913838120101;7.919907651715036;7.179545454545453;7.959721485411147;8.048632707774802;7.793649350649352 04:19:23 INFO - PROCESS | 1652 | |7;240p.120fps.mp4_scale_2_inclip;7.782743190661482;7.876929133858274;8.067338709677408;7.6669157088122555;7.968107569721112;7.549886792452835;7.783599221789891;7.329505494505501;7.666417624521078;7.816171874999995;7.757829457364343;7.274981818181814 04:19:23 INFO - PROCESS | 1652 | |8;480p.60fps.webm_scale_fullscreen_startup;10.652180851063832;10.802949640287775;10.569137323943655;10.95204379562044;11.051360294117652;10.95135036496351;10.533245614035083;10.312216494845359;11.03314338235294;10.832472924187718;10.603727915194344;10.565845070422538 04:19:23 INFO - PROCESS | 1652 | |9;480p.60fps.webm_scale_fullscreen_inclip;9.530809523809513;9.621538461538474;9.485023696682465;9.812352941176458;9.571746411483248;9.525547619047627;9.304186046511635;9.667971014492755;9.397065727699534;9.812205882352952;9.902202970297024;9.76131707317073 04:19:23 INFO - PROCESS | 1652 | |10;480p.60fps.webm_scale_1_startup;4.666321928460341;4.762293650793649;4.801568;4.967748344370862;4.935205592105262;4.696384976525824;4.918967213114754;4.566765601217653;4.6898984375;4.943607907742993;4.7959584664536745;4.952475247524753 04:19:23 INFO - PROCESS | 1652 | |11;480p.60fps.webm_scale_1_inclip;4.0916768916155455;4.196215932914049;4.03583669354839;4.330119047619054;4.249214437367306;4.151151452282157;4.378796498905909;4.177275574112737;4.140693581780542;4.414834437086097;4.360544662309364;4.294463519313299 04:19:23 INFO - PROCESS | 1652 | |12;480p.60fps.webm_scale_1.1_startup;4.519118975903614;4.735394321766559;4.769475357710646;4.92133606557377;4.785988835725681;4.816059390048152;4.532877643504525;4.622681047765792;4.637766615146829;4.894567699836872;4.779060509554146;4.718309748427675 04:19:23 INFO - PROCESS | 1652 | |13;480p.60fps.webm_scale_1.1_inclip;4.58973623853211;4.8089302884615375;4.7300472813238885;4.810468749999997;4.914840294840286;4.867080291970809;4.4554899777283;4.4653236607142945;4.763702380952392;4.878146341463399;4.640348027842222;4.833321256038636 04:19:23 INFO - PROCESS | 1652 | |14;480p.60fps.webm_scale_2_startup;4.839870967741938;4.887092833876226;5.181658031088084;5.588221601489758;5.000866666666673;5.112197614991483;5.000466666666664;5.192102076124561;4.832801932367147;5.173172413793107;5.211336805555561;5.12197098976109 04:19:23 INFO - PROCESS | 1652 | |15;480p.60fps.webm_scale_2_inclip;4.869671532846709;5.002037499999988;4.916130221130234;5.397479784366568;4.963200992555827;5.01416040100251;5.039886649874053;5.0644177215189865;4.730401891252953;5.168901808785525;5.143239074550132;4.821192771084333 04:19:23 INFO - PROCESS | 1652 | |16;1080p.60fps.mp4_scale_fullscreen_startup;69.7962790697674;66.68799999999997;73.17951219512196;63.846808510638205;71.45273809523808;68.20227272727276;76.94307692307709;69.78162790697675;76.93256410256399;73.2020731707318;78.96078947368426;71.45916666666658 04:19:23 INFO - PROCESS | 1652 | |17;1080p.60fps.mp4_scale_fullscreen_inclip;62.52187499999991;64.53258064516136;66.68400000000014;62.5065625000002;66.68299999999994;68.98051724137949;62.535468749999836;71.42624999999991;71.43482142857154;76.92961538461532;66.67083333333333;66.69733333333352 04:19:23 INFO - PROCESS | 1652 | |18;1080p.60fps.mp4_scale_1_startup;48.390564516128975;41.68597222222232;47.635079365079285;44.78007462686566;49.186885245901664;47.63547619047613;50.00616666666671;45.463863636363605;42.87221428571429;45.458333333333336;46.876171874999955;44.78358208955224 04:19:23 INFO - PROCESS | 1652 | |19;1080p.60fps.mp4_scale_1_inclip;37.056944444444525;46.53883720930229;44.4514444444445;46.520465116279176;47.64642857142861;40.00830000000002;43.5;40.01899999999994;40.010899999999964;45.46090909090906;47.62285714285723;37.75132075471711 04:19:23 INFO - PROCESS | 1652 | |20;1080p.60fps.mp4_scale_1.1_startup;43.49340579710153;48.396129032258024;42.86707142857142;46.170230769230805;50.86000000000009;42.25457746478869;48.4021774193548;48.40991935483872;46.161384615384584;50.00766666666665;50.01433333333334;54.56190909090907 04:19:23 INFO - PROCESS | 1652 | |21;1080p.60fps.mp4_scale_1.1_inclip;40.83897959183675;50.007875000000055;45.455681818181716;47.62190476190482;42.57170212765948;44.455777777777826;43.503369565217525;44.46344444444451;44.4633333333333;40.82581632653054;44.47177777777785;47.626071428571386 04:19:23 INFO - PROCESS | 1652 | |22;1080p.60fps.mp4_scale_2_startup;42.867928571428536;45.46333333333336;47.63761904761902;48.394354838709745;44.125;46.164076923076934;49.1909836065574;45.46901515151518;50.86728813559319;45.47143939393948;50.84618644067789;47.636111111111184 04:19:23 INFO - PROCESS | 1652 | |23;1080p.60fps.mp4_scale_2_inclip;44.443777777777804;40.8324489795917;41.70770833333336;46.55976744186046;43.4906521739132;43.5393478260869;46.54674418604639;43.50967391304347;44.46311111111103;44.464111111110995;47.63738095238105;45.47204545454538 04:19:23 INFO - PROCESS | 1652 | __end_tp_report 04:19:23 INFO - PROCESS | 1652 | __start_cc_report 04:19:23 INFO - PROCESS | 1652 | _x_x_mozilla_cycle_collect,976 04:19:23 INFO - PROCESS | 1652 | __end_cc_report 04:19:23 INFO - PROCESS | 1652 | __startTimestamp1468235963973__endTimestamp 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | ------- Summary: start ------- 04:19:23 INFO - PROCESS | 1652 | Number of tests: 24 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | [#0] 240p.120fps.mp4_scale_fullscreen_startup Cycles:12 Average:21.45 Median:21.52 stddev:0.96 (4.5%) stddev-sans-first:0.89 04:19:23 INFO - PROCESS | 1652 | Values: 22.9 20.6 20.7 20.3 21.6 23.3 22.4 20.6 21.0 21.1 21.4 21.6 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | [#1] 240p.120fps.mp4_scale_fullscreen_inclip Cycles:12 Average:20.24 Median:20.31 stddev:0.77 (3.8%) stddev-sans-first:0.78 04:19:23 INFO - PROCESS | 1652 | Values: 19.6 19.6 20.4 20.0 19.4 19.4 20.2 20.6 20.4 21.8 19.8 21.5 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | [#2] 240p.120fps.mp4_scale_1_startup Cycles:12 Average:5.74 Median:5.75 stddev:0.12 (2.1%) stddev-sans-first:0.13 04:19:23 INFO - PROCESS | 1652 | Values: 5.7 5.6 5.8 5.7 5.8 5.7 5.7 5.8 5.6 5.6 5.8 6.0 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | [#3] 240p.120fps.mp4_scale_1_inclip Cycles:12 Average:5.01 Median:5.06 stddev:0.20 (4.0%) stddev-sans-first:0.20 04:19:23 INFO - PROCESS | 1652 | Values: 5.2 4.9 4.8 4.8 5.2 4.9 5.4 5.1 4.9 4.9 5.0 5.2 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | [#4] 240p.120fps.mp4_scale_1.1_startup Cycles:12 Average:5.49 Median:5.60 stddev:0.24 (4.4%) stddev-sans-first:0.26 04:19:23 INFO - PROCESS | 1652 | Values: 5.5 5.4 5.6 5.1 5.6 5.2 5.5 5.8 5.7 5.8 5.1 5.7 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | [#5] 240p.120fps.mp4_scale_1.1_inclip Cycles:12 Average:5.41 Median:5.41 stddev:0.24 (4.4%) stddev-sans-first:0.24 04:19:23 INFO - PROCESS | 1652 | Values: 5.6 5.1 5.4 5.2 5.4 5.2 5.5 5.4 5.3 6.0 5.3 5.4 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | [#6] 240p.120fps.mp4_scale_2_startup Cycles:12 Average:7.76 Median:7.89 stddev:0.34 (4.3%) stddev-sans-first:0.35 04:19:23 INFO - PROCESS | 1652 | Values: 7.7 7.4 8.0 7.9 7.2 8.2 7.8 7.9 7.2 8.0 8.0 7.8 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | [#7] 240p.120fps.mp4_scale_2_inclip Cycles:12 Average:7.71 Median:7.78 stddev:0.24 (3.0%) stddev-sans-first:0.25 04:19:23 INFO - PROCESS | 1652 | Values: 7.8 7.9 8.1 7.7 8.0 7.5 7.8 7.3 7.7 7.8 7.8 7.3 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | [#8] 480p.60fps.webm_scale_fullscreen_startup Cycles:12 Average:10.74 Median:10.82 stddev:0.23 (2.2%) stddev-sans-first:0.24 04:19:23 INFO - PROCESS | 1652 | Values: 10.7 10.8 10.6 11.0 11.1 11.0 10.5 10.3 11.0 10.8 10.6 10.6 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | [#9] 480p.60fps.webm_scale_fullscreen_inclip Cycles:12 Average:9.62 Median:9.64 stddev:0.18 (1.9%) stddev-sans-first:0.19 04:19:23 INFO - PROCESS | 1652 | Values: 9.5 9.6 9.5 9.8 9.6 9.5 9.3 9.7 9.4 9.8 9.9 9.8 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | [#10] 480p.60fps.webm_scale_1_startup Cycles:12 Average:4.81 Median:4.86 stddev:0.13 (2.8%) stddev-sans-first:0.13 04:19:23 INFO - PROCESS | 1652 | Values: 4.7 4.8 4.8 5.0 4.9 4.7 4.9 4.6 4.7 4.9 4.8 5.0 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | [#11] 480p.60fps.webm_scale_1_inclip Cycles:12 Average:4.24 Median:4.27 stddev:0.12 (2.8%) stddev-sans-first:0.12 04:19:23 INFO - PROCESS | 1652 | Values: 4.1 4.2 4.0 4.3 4.2 4.2 4.4 4.2 4.1 4.4 4.4 4.3 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | [#12] 480p.60fps.webm_scale_1.1_startup Cycles:12 Average:4.73 Median:4.77 stddev:0.13 (2.7%) stddev-sans-first:0.12 04:19:23 INFO - PROCESS | 1652 | Values: 4.5 4.7 4.8 4.9 4.8 4.8 4.5 4.6 4.6 4.9 4.8 4.7 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | [#13] 480p.60fps.webm_scale_1.1_inclip Cycles:12 Average:4.73 Median:4.81 stddev:0.16 (3.3%) stddev-sans-first:0.16 04:19:23 INFO - PROCESS | 1652 | Values: 4.6 4.8 4.7 4.8 4.9 4.9 4.5 4.5 4.8 4.9 4.6 4.8 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | [#14] 480p.60fps.webm_scale_2_startup Cycles:12 Average:5.10 Median:5.15 stddev:0.21 (4.0%) stddev-sans-first:0.20 04:19:23 INFO - PROCESS | 1652 | Values: 4.8 4.9 5.2 5.6 5.0 5.1 5.0 5.2 4.8 5.2 5.2 5.1 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | [#15] 480p.60fps.webm_scale_2_inclip Cycles:12 Average:5.01 Median:5.03 stddev:0.18 (3.5%) stddev-sans-first:0.18 04:19:23 INFO - PROCESS | 1652 | Values: 4.9 5.0 4.9 5.4 5.0 5.0 5.0 5.1 4.7 5.2 5.1 4.8 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | [#16] 1080p.60fps.mp4_scale_fullscreen_startup Cycles:12 Average:71.70 Median:72.32 stddev:4.46 (6.2%) stddev-sans-first:4.63 04:19:23 INFO - PROCESS | 1652 | Values: 69.8 66.7 73.2 63.8 71.5 68.2 76.9 69.8 76.9 73.2 79.0 71.5 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | [#17] 1080p.60fps.mp4_scale_fullscreen_inclip Cycles:12 Average:67.30 Median:66.69 stddev:4.34 (6.5%) stddev-sans-first:4.27 04:19:23 INFO - PROCESS | 1652 | Values: 62.5 64.5 66.7 62.5 66.7 69.0 62.5 71.4 71.4 76.9 66.7 66.7 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | [#18] 1080p.60fps.mp4_scale_1_startup Cycles:12 Average:46.23 Median:47.26 stddev:2.51 (5.3%) stddev-sans-first:2.53 04:19:23 INFO - PROCESS | 1652 | Values: 48.4 41.7 47.6 44.8 49.2 47.6 50.0 45.5 42.9 45.5 46.9 44.8 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | [#19] 1080p.60fps.mp4_scale_1_inclip Cycles:12 Average:43.05 Median:44.96 stddev:3.88 (8.6%) stddev-sans-first:3.56 04:19:23 INFO - PROCESS | 1652 | Values: 37.1 46.5 44.5 46.5 47.6 40.0 43.5 40.0 40.0 45.5 47.6 37.8 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | [#20] 1080p.60fps.mp4_scale_1.1_startup Cycles:12 Average:47.63 Median:48.41 stddev:3.63 (7.5%) stddev-sans-first:3.55 04:19:23 INFO - PROCESS | 1652 | Values: 43.5 48.4 42.9 46.2 50.9 42.3 48.4 48.4 46.2 50.0 50.0 54.6 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | [#21] 1080p.60fps.mp4_scale_1.1_inclip Cycles:12 Average:44.69 Median:44.47 stddev:2.73 (6.1%) stddev-sans-first:2.56 04:19:23 INFO - PROCESS | 1652 | Values: 40.8 50.0 45.5 47.6 42.6 44.5 43.5 44.5 44.5 40.8 44.5 47.6 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | [#22] 1080p.60fps.mp4_scale_2_startup Cycles:12 Average:47.01 Median:47.64 stddev:2.53 (5.3%) stddev-sans-first:2.27 04:19:23 INFO - PROCESS | 1652 | Values: 42.9 45.5 47.6 48.4 44.1 46.2 49.2 45.5 50.9 45.5 50.8 47.6 04:19:23 INFO - PROCESS | 1652 | 04:19:23 INFO - PROCESS | 1652 | [#23] 1080p.60fps.mp4_scale_2_inclip Cycles:12 Average:44.39 Median:44.46 stddev:1.98 (4.5%) stddev-sans-first:2.08 04:19:23 INFO - PROCESS | 1652 | Values: 44.4 40.8 41.7 46.6 43.5 43.5 46.5 43.5 44.5 44.5 47.6 45.5 04:19:23 INFO - PROCESS | 1652 | -------- Summary: end -------- 04:19:23 INFO - PROCESS | 1652 | 04:19:24 INFO - TEST-INFO | 1652: exit 0 04:19:24 INFO - TEST-OK | basic_compositor_video | took 775177ms 04:19:24 INFO - SUITE-END | took 775s 04:19:24 INFO - Completed test suite (00:12:55) 04:19:24 INFO - PERFHERDER_DATA: {"framework": {"name": "talos"}, "suites": [{"extraOptions": ["e10s"], "name": "basic_compositor_video", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 13.913474118007702, "subtests": [{"name": "240p.120fps.mp4_scale_fullscreen_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [22.908664122137402, 20.558321917808218, 20.703862068965517, 20.279831081081085, 21.58679856115108, 23.262248062015505, 22.394626865671643, 20.556027397260277, 20.9836013986014, 21.134894366197184, 21.44407142857143, 21.589136690647482], "value": 21.134894366197184, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_fullscreen_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [19.612401960784315, 19.61686274509804, 20.416785714285712, 20.0075, 19.426601941747574, 19.420922330097085, 20.21272727272727, 20.625206185567016, 20.446785714285717, 21.752717391304344, 19.807970297029705, 21.505376344086027], "value": 20.21272727272727, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.71695238095238, 5.599365671641792, 5.78553949903661, 5.714933333333334, 5.780693641618499, 5.726851145038166, 5.693548387096774, 5.838686770428014, 5.584934944237918, 5.640216165413534, 5.800888030888032, 6.028222891566264], "value": 5.726851145038166, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.183380829015544, 4.917714987714988, 4.787236842105265, 4.7535391923990495, 5.211210937499999, 4.85742718446602, 5.364048257372657, 5.142699228791774, 4.90469362745098, 4.855097087378639, 4.97691542288557, 5.222624020887731], "value": 4.917714987714988, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.4748448905109495, 5.367119856887298, 5.629727954971858, 5.116933560477004, 5.566846011131723, 5.183721934369602, 5.474589416058392, 5.769750000000001, 5.7177333333333324, 5.758032629558544, 5.140556506849316, 5.7262404580152655], "value": 5.566846011131723, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.635112676056338, 5.1024744897959184, 5.378400537634407, 5.2230026109660574, 5.439062500000002, 5.196987012987013, 5.450204359673026, 5.437472826086956, 5.349732620320854, 6.026551204819273, 5.33717333333333, 5.350802139037435], "value": 5.350802139037435, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [7.713547557840611, 7.371793611793611, 8.02723262032086, 7.856963350785342, 7.178373205741625, 8.175803814713893, 7.835913838120101, 7.919907651715036, 7.179545454545453, 7.959721485411147, 8.048632707774802, 7.793649350649352], "value": 7.856963350785342, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [7.782743190661482, 7.876929133858274, 8.067338709677408, 7.6669157088122555, 7.968107569721112, 7.549886792452835, 7.783599221789891, 7.329505494505501, 7.666417624521078, 7.816171874999995, 7.757829457364343, 7.274981818181814], "value": 7.757829457364343, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_fullscreen_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.652180851063832, 10.802949640287775, 10.569137323943655, 10.95204379562044, 11.051360294117652, 10.95135036496351, 10.533245614035083, 10.312216494845359, 11.03314338235294, 10.832472924187718, 10.603727915194344, 10.565845070422538], "value": 10.802949640287775, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_fullscreen_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [9.530809523809513, 9.621538461538474, 9.485023696682465, 9.812352941176458, 9.571746411483248, 9.525547619047627, 9.304186046511635, 9.667971014492755, 9.397065727699534, 9.812205882352952, 9.902202970297024, 9.76131707317073], "value": 9.621538461538474, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.666321928460341, 4.762293650793649, 4.801568, 4.967748344370862, 4.935205592105262, 4.696384976525824, 4.918967213114754, 4.566765601217653, 4.6898984375, 4.943607907742993, 4.7959584664536745, 4.952475247524753], "value": 4.801568, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.0916768916155455, 4.196215932914049, 4.03583669354839, 4.330119047619054, 4.249214437367306, 4.151151452282157, 4.378796498905909, 4.177275574112737, 4.140693581780542, 4.414834437086097, 4.360544662309364, 4.294463519313299], "value": 4.249214437367306, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.519118975903614, 4.735394321766559, 4.769475357710646, 4.92133606557377, 4.785988835725681, 4.816059390048152, 4.532877643504525, 4.622681047765792, 4.637766615146829, 4.894567699836872, 4.779060509554146, 4.718309748427675], "value": 4.769475357710646, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.58973623853211, 4.8089302884615375, 4.7300472813238885, 4.810468749999997, 4.914840294840286, 4.867080291970809, 4.4554899777283, 4.4653236607142945, 4.763702380952392, 4.878146341463399, 4.640348027842222, 4.833321256038636], "value": 4.8089302884615375, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.839870967741938, 4.887092833876226, 5.181658031088084, 5.588221601489758, 5.000866666666673, 5.112197614991483, 5.000466666666664, 5.192102076124561, 4.832801932367147, 5.173172413793107, 5.211336805555561, 5.12197098976109], "value": 5.12197098976109, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.869671532846709, 5.002037499999988, 4.916130221130234, 5.397479784366568, 4.963200992555827, 5.01416040100251, 5.039886649874053, 5.0644177215189865, 4.730401891252953, 5.168901808785525, 5.143239074550132, 4.821192771084333], "value": 5.01416040100251, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_fullscreen_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [69.7962790697674, 66.68799999999997, 73.17951219512196, 63.846808510638205, 71.45273809523808, 68.20227272727276, 76.94307692307709, 69.78162790697675, 76.93256410256399, 73.2020731707318, 78.96078947368426, 71.45916666666658], "value": 71.45916666666658, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_fullscreen_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [62.52187499999991, 64.53258064516136, 66.68400000000014, 62.5065625000002, 66.68299999999994, 68.98051724137949, 62.535468749999836, 71.42624999999991, 71.43482142857154, 76.92961538461532, 66.67083333333333, 66.69733333333352], "value": 66.68400000000014, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [48.390564516128975, 41.68597222222232, 47.635079365079285, 44.78007462686566, 49.186885245901664, 47.63547619047613, 50.00616666666671, 45.463863636363605, 42.87221428571429, 45.458333333333336, 46.876171874999955, 44.78358208955224], "value": 45.463863636363605, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [37.056944444444525, 46.53883720930229, 44.4514444444445, 46.520465116279176, 47.64642857142861, 40.00830000000002, 43.5, 40.01899999999994, 40.010899999999964, 45.46090909090906, 47.62285714285723, 37.75132075471711], "value": 44.4514444444445, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [43.49340579710153, 48.396129032258024, 42.86707142857142, 46.170230769230805, 50.86000000000009, 42.25457746478869, 48.4021774193548, 48.40991935483872, 46.161384615384584, 50.00766666666665, 50.01433333333334, 54.56190909090907], "value": 48.4021774193548, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [40.83897959183675, 50.007875000000055, 45.455681818181716, 47.62190476190482, 42.57170212765948, 44.455777777777826, 43.503369565217525, 44.46344444444451, 44.4633333333333, 40.82581632653054, 44.47177777777785, 47.626071428571386], "value": 44.46344444444451, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [42.867928571428536, 45.46333333333336, 47.63761904761902, 48.394354838709745, 44.125, 46.164076923076934, 49.1909836065574, 45.46901515151518, 50.86728813559319, 45.47143939393948, 50.84618644067789, 47.636111111111184], "value": 47.636111111111184, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [44.443777777777804, 40.8324489795917, 41.70770833333336, 46.55976744186046, 43.4906521739132, 43.5393478260869, 46.54674418604639, 43.50967391304347, 44.46311111111103, 44.464111111110995, 47.63738095238105, 45.47204545454538], "value": 44.46311111111103, "unit": "ms/frame"}]}]} 04:19:25 INFO - Return code: 0 04:19:25 INFO - Validating PERFHERDER_DATA against /builds/slave/test/scripts/external_tools/performance-artifact-schema.json 04:19:25 ERROR - # TBPL SUCCESS # 04:19:25 INFO - Running pre test command check_screen_resolution with 'bash -c screenresolution get && screenresolution list && system_profiler SPDisplaysDataType' 04:19:25 INFO - Running command: ['bash', '-c', 'screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'] in /builds/slave/test/build 04:19:25 INFO - Copy/paste: bash -c "screenresolution get && screenresolution list && system_profiler SPDisplaysDataType" 04:19:25 INFO - 2016-07-11 04:19:25.089 screenresolution[1665:12927] starting screenresolution argv=screenresolution get 04:19:25 INFO - 2016-07-11 04:19:25.092 screenresolution[1665:12927] Display 0: 1600x1200x32@60 04:19:25 INFO - 2016-07-11 04:19:25.097 screenresolution[1666:12929] starting screenresolution argv=screenresolution list 04:19:25 INFO - Available Modes on Display 0 04:19:25 INFO - 1600x1200x32@60 1152x870x32@75 1280x1024x32@75 04:19:25 INFO - 1024x768x32@75 1024x768x32@70 1024x768x32@60 04:19:25 INFO - 800x600x32@75 800x600x32@60 640x480x32@75 04:19:25 INFO - 640x480x32@60 1280x1024x32@60 1280x960x32@60 04:19:25 INFO - 1280x960x32@75 1344x1008x32@60 Graphics/Displays: 04:19:25 INFO - Intel Iris: 04:19:25 INFO - Chipset Model: Intel Iris 04:19:25 INFO - Type: GPU 04:19:25 INFO - Bus: Built-In 04:19:25 INFO - VRAM (Dynamic, Max): 1536 MB 04:19:25 INFO - Vendor: Intel (0x8086) 04:19:25 INFO - Device ID: 0x0a2e 04:19:25 INFO - Revision ID: 0x0009 04:19:25 INFO - Displays: 04:19:25 INFO - Display: 04:19:25 INFO - Resolution: 1600 x 1200 @ 60 Hz 04:19:25 INFO - Pixel Depth: 32-Bit Color (ARGB8888) 04:19:25 INFO - Display Serial Number: 1600x1200 60 04:19:25 INFO - Main Display: Yes 04:19:25 INFO - Mirror: Off 04:19:25 INFO - Online: Yes 04:19:25 INFO - Rotation: Supported 04:19:25 INFO - Return code: 0 04:19:25 INFO - Running post-action listener: _resource_record_post_action 04:19:25 INFO - ##### 04:19:25 INFO - ##### Finished run-tests step (success) 04:19:25 INFO - ##### 04:19:25 INFO - Running post-run listener: _resource_record_post_run 04:19:25 INFO - Total resource usage - Wall time: 812s; CPU: 81.0%; Read bytes: 38190080; Write bytes: 589791744; Read time: 392; Write time: 1669 04:19:25 INFO - TinderboxPrint: CPU usage
81.4% 04:19:25 INFO - TinderboxPrint: I/O read bytes / time
38,190,080 / 392 04:19:25 INFO - TinderboxPrint: I/O write bytes / time
589,791,744 / 1,669 04:19:25 INFO - TinderboxPrint: CPU idle
604.2 (18.6%) 04:19:25 INFO - TinderboxPrint: CPU system
1,064.0 (32.8%) 04:19:25 INFO - TinderboxPrint: CPU user
1,577.8 (48.6%) 04:19:25 INFO - TinderboxPrint: Swap in / out
446,226,432 / 0 04:19:25 INFO - install - Wall time: 35s; CPU: 55.0%; Read bytes: 407429632; Write bytes: 395736576; Read time: 31012; Write time: 727 04:19:25 INFO - run-tests - Wall time: 777s; CPU: 83.0%; Read bytes: 30852096; Write bytes: 180395008; Read time: 302; Write time: 906 04:19:25 INFO - Running post-run listener: _upload_blobber_files 04:19:25 INFO - Blob upload gear active. 04:19:25 INFO - Preparing to upload files from /builds/slave/test/build/blobber_upload_dir. 04:19:25 INFO - Files from /builds/slave/test/build/blobber_upload_dir are to be uploaded with branch at the following location(s): https://blobupload.elasticbeanstalk.com 04:19:25 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/venv/bin/blobberc.py', '-u', 'https://blobupload.elasticbeanstalk.com', '-a', '/builds/slave/test/oauth.txt', '-b', 'Fx-Team', '-d', '/builds/slave/test/build/blobber_upload_dir', '--output-manifest', '/builds/slave/test/build/uploaded_files.json'] 04:19:25 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/venv/bin/blobberc.py -u https://blobupload.elasticbeanstalk.com -a /builds/slave/test/oauth.txt -b Fx-Team -d /builds/slave/test/build/blobber_upload_dir --output-manifest /builds/slave/test/build/uploaded_files.json 04:19:26 INFO - (blobuploader) - INFO - Open directory for files ... 04:19:26 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-e10s_errorsummary.log ... 04:19:26 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 04:19:26 INFO - (blobuploader) - INFO - Uploading, attempt #1. 04:19:27 INFO - (blobuploader) - INFO - TinderboxPrint: g4-e10s_errorsummary.log: uploaded 04:19:27 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 04:19:27 INFO - (blobuploader) - INFO - Done attempting. 04:19:27 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-e10s_raw.log ... 04:19:27 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 04:19:27 INFO - (blobuploader) - INFO - Uploading, attempt #1. 04:19:28 INFO - (blobuploader) - INFO - TinderboxPrint: g4-e10s_raw.log: uploaded 04:19:28 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 04:19:28 INFO - (blobuploader) - INFO - Done attempting. 04:19:28 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/resource-usage.json ... 04:19:28 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 04:19:28 INFO - (blobuploader) - INFO - Uploading, attempt #1. 04:19:30 INFO - (blobuploader) - INFO - TinderboxPrint: resource-usage.json: uploaded 04:19:30 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 04:19:30 INFO - (blobuploader) - INFO - Done attempting. 04:19:30 INFO - (blobuploader) - INFO - Iteration through files over. 04:19:30 INFO - Return code: 0 04:19:30 INFO - rmtree: /builds/slave/test/build/uploaded_files.json 04:19:30 INFO - retry: Calling remove with args: ('/builds/slave/test/build/uploaded_files.json',), kwargs: {}, attempt #1 04:19:30 INFO - Setting buildbot property blobber_files to {"g4-e10s_errorsummary.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Fx-Team/sha512/82feede00661d99bc02ca1d1c32ed6e3b7944f26bf587cd64d2fabe1fe0e73a11b6f72de9e618dd8feb3fd7d11ca62d6bbdf94229130b8674611806b61413641", "resource-usage.json": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Fx-Team/sha512/d436208e76217bdbb584a5d1725e26bc0d44e41f810083fb3d7ca0981ff72bc78723e75a7d4822833df41661f653efb536ae5a398fde93abf05ce524684d3fcc", "g4-e10s_raw.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Fx-Team/sha512/bb33763dedab1a9d6122048b226983dd1d931bdb06a4ca0c6b3a2fd11ffe42bf8a995e9a334ae3d706328800cb4534ac4ff777724e6001a88399045909a342fd"} 04:19:30 INFO - Writing buildbot properties ['blobber_files'] to /builds/slave/test/properties/blobber_files 04:19:30 INFO - Writing to file /builds/slave/test/properties/blobber_files 04:19:30 INFO - Contents: 04:19:30 INFO - blobber_files:{"g4-e10s_errorsummary.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Fx-Team/sha512/82feede00661d99bc02ca1d1c32ed6e3b7944f26bf587cd64d2fabe1fe0e73a11b6f72de9e618dd8feb3fd7d11ca62d6bbdf94229130b8674611806b61413641", "resource-usage.json": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Fx-Team/sha512/d436208e76217bdbb584a5d1725e26bc0d44e41f810083fb3d7ca0981ff72bc78723e75a7d4822833df41661f653efb536ae5a398fde93abf05ce524684d3fcc", "g4-e10s_raw.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Fx-Team/sha512/bb33763dedab1a9d6122048b226983dd1d931bdb06a4ca0c6b3a2fd11ffe42bf8a995e9a334ae3d706328800cb4534ac4ff777724e6001a88399045909a342fd"} 04:19:30 INFO - Running post-run listener: copy_logs_to_upload_dir 04:19:30 INFO - Copying logs to upload dir... 04:19:30 INFO - mkdir: /builds/slave/test/build/upload/logs 04:19:30 INFO - Copying logs to upload dir... program finished with exit code 0 elapsedTime=867.672392 ========= master_lag: 0.04 ========= ========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 14 mins, 27 secs) (at 2016-07-11 04:19:30.587961) ========= ========= Started set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2016-07-11 04:19:30.591089) ========= bash -c 'for file in `ls -1`; do cat $file; done' in dir /builds/slave/test/properties (timeout 1200 secs) watching logfiles {} argv: ['bash', '-c', 'for file in `ls -1`; do cat $file; done'] environment: Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.60BmflXbZZ/Render GIT_SHARE_BASE_DIR=/builds/git-shared HG_SHARE_BASE_DIR=/builds/hg-shared HOME=/Users/cltbld IDLEIZER_DISABLE_SHUTDOWN=true LOGNAME=cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NO_EM_RESTART=1 PAGER=/bin/cat PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11 PWD=/builds/slave/test/properties RUNNER_CONFIG_CMD=/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg SHELL=/bin/bash SSH_AUTH_SOCK=/private/tmp/com.apple.launchd.MN4hGYEesj/Listeners TMPDIR=/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/ TWISTD_LOG_PATH=/builds/slave/twistd.log USER=cltbld VERSIONER_PYTHON_PREFER_32_BIT=no VERSIONER_PYTHON_VERSION=2.7 XPCOM_DEBUG_BREAK=warn XPC_FLAGS=0x0 XPC_SERVICE_NAME=0 __CF_USER_TEXT_ENCODING=0x1C:0:0 using PTY: False blobber_files:{"g4-e10s_errorsummary.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Fx-Team/sha512/82feede00661d99bc02ca1d1c32ed6e3b7944f26bf587cd64d2fabe1fe0e73a11b6f72de9e618dd8feb3fd7d11ca62d6bbdf94229130b8674611806b61413641", "resource-usage.json": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Fx-Team/sha512/d436208e76217bdbb584a5d1725e26bc0d44e41f810083fb3d7ca0981ff72bc78723e75a7d4822833df41661f653efb536ae5a398fde93abf05ce524684d3fcc", "g4-e10s_raw.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Fx-Team/sha512/bb33763dedab1a9d6122048b226983dd1d931bdb06a4ca0c6b3a2fd11ffe42bf8a995e9a334ae3d706328800cb4534ac4ff777724e6001a88399045909a342fd"} build_url:https://queue.taskcluster.net/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.dmg program finished with exit code 0 elapsedTime=0.010491 build_url: 'https://queue.taskcluster.net/v1/task/DRrwKSd2TGC_8jM2R0HO5Q/artifacts/public/build/firefox-50.0a1.en-US.mac.dmg' blobber_files: '{"g4-e10s_errorsummary.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Fx-Team/sha512/82feede00661d99bc02ca1d1c32ed6e3b7944f26bf587cd64d2fabe1fe0e73a11b6f72de9e618dd8feb3fd7d11ca62d6bbdf94229130b8674611806b61413641", "resource-usage.json": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Fx-Team/sha512/d436208e76217bdbb584a5d1725e26bc0d44e41f810083fb3d7ca0981ff72bc78723e75a7d4822833df41661f653efb536ae5a398fde93abf05ce524684d3fcc", "g4-e10s_raw.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Fx-Team/sha512/bb33763dedab1a9d6122048b226983dd1d931bdb06a4ca0c6b3a2fd11ffe42bf8a995e9a334ae3d706328800cb4534ac4ff777724e6001a88399045909a342fd"}' ========= master_lag: 0.02 ========= ========= Finished set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2016-07-11 04:19:30.623136) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2016-07-11 04:19:30.623451) ========= rm -f oauth.txt in dir /builds/slave/test/. (timeout 1200 secs) watching logfiles {} argv: ['rm', '-f', 'oauth.txt'] environment: Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.60BmflXbZZ/Render GIT_SHARE_BASE_DIR=/builds/git-shared HG_SHARE_BASE_DIR=/builds/hg-shared HOME=/Users/cltbld IDLEIZER_DISABLE_SHUTDOWN=true LOGNAME=cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NO_EM_RESTART=1 PAGER=/bin/cat PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11 PWD=/builds/slave/test RUNNER_CONFIG_CMD=/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg SHELL=/bin/bash SSH_AUTH_SOCK=/private/tmp/com.apple.launchd.MN4hGYEesj/Listeners TMPDIR=/var/folders/gh/t76btwz501jcblhsxv28_zf400000w/T/ TWISTD_LOG_PATH=/builds/slave/twistd.log USER=cltbld VERSIONER_PYTHON_PREFER_32_BIT=no VERSIONER_PYTHON_VERSION=2.7 XPCOM_DEBUG_BREAK=warn XPC_FLAGS=0x0 XPC_SERVICE_NAME=0 __CF_USER_TEXT_ENCODING=0x1C:0:0 using PTY: False program finished with exit code 0 elapsedTime=0.005203 ========= master_lag: 0.04 ========= ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2016-07-11 04:19:30.673251) ========= ========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2016-07-11 04:19:30.673648) ========= ========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2016-07-11 04:19:30.674044) ========= ========= Total master_lag: 0.17 =========