builder: fx-team_yosemite_test-other-e10s slave: t-yosemite-r5-0016 starttime: 1447466725.26 results: success (0) buildid: 20151113165331 builduid: e98c542f62a34925ae0bfbf033bc1410 revision: 031994a3b4e47b1d9ad1c0e4be0b98bdc4e7e242 ========= Started set props: master (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:25.256574) ========= master: http://buildbot-master107.bb.releng.scl3.mozilla.com:8201/ ========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:25.257132) ========= ========= Started set props: basedir (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:25.257523) ========= bash -c pwd in dir /builds/slave/test/. (timeout 1200 secs) watching logfiles {} argv: ['bash', '-c', 'pwd'] environment: Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.NpFlPSwRQX/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.u2RYEBHvJR/Listeners TMPDIR=/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/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:0x0:0x0 using PTY: False /builds/slave/test program finished with exit code 0 elapsedTime=0.006069 basedir: '/builds/slave/test' ========= master_lag: 0.32 ========= ========= Finished set props: basedir (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:25.578824) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:25.579189) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:25.608227) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:25.608588) ========= rm -rf properties in dir /builds/slave/test/. (timeout 1200 secs) watching logfiles {} argv: ['rm', '-rf', 'properties'] environment: Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.NpFlPSwRQX/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.u2RYEBHvJR/Listeners TMPDIR=/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/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:0x0:0x0 using PTY: False program finished with exit code 0 elapsedTime=0.012396 ========= master_lag: 0.04 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:25.658455) ========= ========= Started set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:25.658811) ========= script_repo_url: https://hg.mozilla.org/build/mozharness ========= Finished set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:25.659272) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:25.659632) ========= 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.NpFlPSwRQX/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.u2RYEBHvJR/Listeners TMPDIR=/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/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:0x0:0x0 using PTY: False --2015-11-13 18:05:25-- https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py Resolving hg.mozilla.org... 63.245.215.25, 63.245.215.102, 63.245.215.102, ... Connecting to hg.mozilla.org|63.245.215.25|:443... connected. HTTP request sent, awaiting response... 200 Script output follows Length: 12141 (12K) [text/x-python] Saving to: `archiver_client.py' 0K .......... . 100% 9.51M=0.001s 2015-11-13 18:05:25 (9.51 MB/s) - `archiver_client.py' saved [12141/12141] program finished with exit code 0 elapsedTime=0.256367 ========= master_lag: 0.02 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:25.932698) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:25.933096) ========= rm -rf scripts in dir /builds/slave/test/. (timeout 1200 secs) watching logfiles {} argv: ['rm', '-rf', 'scripts'] environment: Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.NpFlPSwRQX/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.u2RYEBHvJR/Listeners TMPDIR=/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/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:0x0:0x0 using PTY: False program finished with exit code 0 elapsedTime=0.147250 ========= master_lag: 0.02 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:26.103068) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 4 secs) (at 2015-11-13 18:05:26.103494) ========= bash -c 'python archiver_client.py mozharness --repo integration/fx-team --rev 031994a3b4e47b1d9ad1c0e4be0b98bdc4e7e242 --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 031994a3b4e47b1d9ad1c0e4be0b98bdc4e7e242 --destination scripts --debug'] environment: Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.NpFlPSwRQX/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.u2RYEBHvJR/Listeners TMPDIR=/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/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:0x0:0x0 using PTY: False 2015-11-13 18:05:26,184 truncating revision to first 12 chars 2015-11-13 18:05:26,184 Setting DEBUG logging. 2015-11-13 18:05:26,184 attempt 1/10 2015-11-13 18:05:26,185 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/integration/fx-team/031994a3b4e4?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness 2015-11-13 18:05:26,537 unpacking tar archive at: fx-team-031994a3b4e4/testing/mozharness/ program finished with exit code 0 elapsedTime=0.814827 ========= master_lag: 4.18 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 4 secs) (at 2015-11-13 18:05:31.100904) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:31.101281) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:31.156422) ========= ========= Started tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:31.156740) ========= TinderboxPrint: script_revlink: https://hg.mozilla.org/build/mozharness/rev/production ========= Finished tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:31.157235) ========= ========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 6 mins, 27 secs) (at 2015-11-13 18:05:31.157605) ========= /tools/buildbot/bin/python scripts/scripts/talos_script.py --suite other-e10s --add-option --webServer,localhost --branch-name Fx-Team --system-bits 64 --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', 'other-e10s', '--add-option', '--webServer,localhost', '--branch-name', 'Fx-Team', '--system-bits', '64', '--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.NpFlPSwRQX/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.u2RYEBHvJR/Listeners TMPDIR=/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/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:0x0:0x0 using PTY: False 18:05:31 INFO - MultiFileLogger online at 20151113 18:05:31 in /builds/slave/test 18:05:31 INFO - Run as scripts/scripts/talos_script.py --suite other-e10s --add-option --webServer,localhost --branch-name Fx-Team --system-bits 64 --cfg talos/mac_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Fx-Team 18:05:31 INFO - Dumping config to /builds/slave/test/logs/localconfig.json. 18:05:31 INFO - {'append_to_log': False, 18:05:31 INFO - 'base_work_dir': '/builds/slave/test', 18:05:31 INFO - 'blob_upload_branch': 'Fx-Team', 18:05:31 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt', 18:05:31 INFO - 'branch': 'Fx-Team', 18:05:31 INFO - 'buildbot_json_path': 'buildprops.json', 18:05:31 INFO - 'config_files': ('talos/mac_config.py',), 18:05:31 INFO - 'default_actions': ('clobber', 18:05:31 INFO - 'read-buildbot-config', 18:05:31 INFO - 'download-and-extract', 18:05:31 INFO - 'populate-webroot', 18:05:31 INFO - 'create-virtualenv', 18:05:31 INFO - 'install', 18:05:31 INFO - 'run-tests'), 18:05:31 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 18:05:31 INFO - 'download_minidump_stackwalk': True, 18:05:31 INFO - 'download_symbols': 'ondemand', 18:05:31 INFO - 'exes': {'python': '/tools/buildbot/bin/python', 18:05:31 INFO - 'tooltool.py': '/tools/tooltool.py', 18:05:31 INFO - 'virtualenv': ('/tools/buildbot/bin/python', 18:05:31 INFO - '/tools/misc-python/virtualenv.py')}, 18:05:31 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 18:05:31 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 18:05:31 INFO - 'installer_path': 'installer.exe', 18:05:31 INFO - 'log_level': 'info', 18:05:31 INFO - 'log_name': 'talos', 18:05:31 INFO - 'log_to_console': True, 18:05:31 INFO - 'minidump_stackwalk_path': 'macosx64-minidump_stackwalk', 18:05:31 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/macosx64/releng.manifest', 18:05:31 INFO - 'opt_config_files': (), 18:05:31 INFO - 'pip_index': False, 18:05:31 INFO - 'postflight_run_cmd_suites': ({'architectures': ('32bit', '64bit'), 18:05:31 INFO - 'cmd': ('bash', 18:05:31 INFO - '-c', 18:05:31 INFO - 'screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'), 18:05:31 INFO - 'enabled': True, 18:05:31 INFO - 'halt_on_failure': False, 18:05:31 INFO - 'name': 'check_screen_resolution'},), 18:05:31 INFO - 'preflight_run_cmd_suites': ({'architectures': ('32bit', '64bit'), 18:05:31 INFO - 'cmd': ('bash', 18:05:31 INFO - '-c', 18:05:31 INFO - 'screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'), 18:05:31 INFO - 'enabled': True, 18:05:31 INFO - 'halt_on_failure': False, 18:05:31 INFO - 'name': 'check_screen_resolution'},), 18:05:31 INFO - 'run_cmd_checks_enabled': True, 18:05:31 INFO - 'sps_profile': False, 18:05:31 INFO - 'sps_profile_interval': 0, 18:05:31 INFO - 'suite': 'other-e10s', 18:05:31 INFO - 'system_bits': '64', 18:05:31 INFO - 'talos_extra_options': ('--webServer', 'localhost'), 18:05:31 INFO - 'title': 't-yosemite-r5-0016', 18:05:31 INFO - 'tooltool_cache': '/builds/tooltool_cache', 18:05:31 INFO - 'use_talos_json': True, 18:05:31 INFO - 'virtualenv_path': '/builds/slave/test/build/venv', 18:05:31 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 18:05:31 INFO - 'work_dir': 'build'} 18:05:31 INFO - ##### 18:05:31 INFO - ##### Running clobber step. 18:05:31 INFO - ##### 18:05:31 INFO - Running pre-action listener: _resource_record_pre_action 18:05:31 INFO - Running main action method: clobber 18:05:31 INFO - rmtree: /builds/slave/test/build 18:05:31 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1 18:05:35 INFO - Running post-action listener: _resource_record_post_action 18:05:35 INFO - ##### 18:05:35 INFO - ##### Running read-buildbot-config step. 18:05:35 INFO - ##### 18:05:35 INFO - Running pre-action listener: _resource_record_pre_action 18:05:35 INFO - Running main action method: read_buildbot_config 18:05:35 INFO - Using buildbot properties: 18:05:35 INFO - { 18:05:35 INFO - "properties": { 18:05:35 INFO - "buildnumber": 305, 18:05:35 INFO - "product": "firefox", 18:05:35 INFO - "script_repo_revision": "production", 18:05:35 INFO - "builddir": "fx-team_yosemite_test-other-e10s", 18:05:35 INFO - "repository": "", 18:05:35 INFO - "buildername": "Rev5 MacOSX Yosemite 10.10 fx-team talos other-e10s", 18:05:35 INFO - "buildid": "20151113165331", 18:05:35 INFO - "slavename": "t-yosemite-r5-0016", 18:05:35 INFO - "pgo_build": "False", 18:05:35 INFO - "basedir": "/builds/slave/test", 18:05:35 INFO - "project": "", 18:05:35 INFO - "platform": "yosemite", 18:05:35 INFO - "master": "http://buildbot-master107.bb.releng.scl3.mozilla.com:8201/", 18:05:35 INFO - "slavebuilddir": "test", 18:05:35 INFO - "scheduler": "tests-fx-team-macosx64-talos", 18:05:35 INFO - "branch": "fx-team", 18:05:35 INFO - "repo_path": "integration/fx-team", 18:05:35 INFO - "stage_platform": "macosx64", 18:05:35 INFO - "builduid": "e98c542f62a34925ae0bfbf033bc1410", 18:05:35 INFO - "revision": "031994a3b4e47b1d9ad1c0e4be0b98bdc4e7e242" 18:05:35 INFO - }, 18:05:35 INFO - "sourcestamp": { 18:05:35 INFO - "repository": "", 18:05:35 INFO - "hasPatch": false, 18:05:35 INFO - "project": "", 18:05:35 INFO - "branch": "fx-team-macosx64-talos", 18:05:35 INFO - "changes": [ 18:05:35 INFO - { 18:05:35 INFO - "category": null, 18:05:35 INFO - "files": [ 18:05:35 INFO - { 18:05:35 INFO - "url": null, 18:05:35 INFO - "name": "https://queue.taskcluster.net/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.dmg" 18:05:35 INFO - } 18:05:35 INFO - ], 18:05:35 INFO - "repository": "", 18:05:35 INFO - "rev": "031994a3b4e47b1d9ad1c0e4be0b98bdc4e7e242", 18:05:35 INFO - "who": "nfitzgerald@mozilla.com", 18:05:35 INFO - "when": 1447466669, 18:05:35 INFO - "number": 6661246, 18:05:35 INFO - "comments": "Bug 1224760 - Improve tree rendering performance by throttling handlers to once per animation frame; r=jsantell\n\nReact.set{State,Props} is supposed to be buffered and only actually trigger a\nre-render once per animation frame, but ends up still doing a lot of mysterious\nand expensive things. We can't tolerate that in our event handlers (especially\nscoll handlers) so instead this commit ensures that they will only happen once\nand on the next animation frame.", 18:05:35 INFO - "project": "", 18:05:35 INFO - "at": "Fri 13 Nov 2015 18:04:29", 18:05:35 INFO - "branch": "fx-team-macosx64-talos", 18:05:35 INFO - "revlink": "", 18:05:35 INFO - "properties": [ 18:05:35 INFO - [ 18:05:35 INFO - "buildid", 18:05:35 INFO - "20151113165331", 18:05:35 INFO - "Change" 18:05:35 INFO - ], 18:05:35 INFO - [ 18:05:35 INFO - "builduid", 18:05:35 INFO - "e98c542f62a34925ae0bfbf033bc1410", 18:05:35 INFO - "Change" 18:05:35 INFO - ], 18:05:35 INFO - [ 18:05:35 INFO - "pgo_build", 18:05:35 INFO - "False", 18:05:35 INFO - "Change" 18:05:35 INFO - ] 18:05:35 INFO - ], 18:05:35 INFO - "revision": "031994a3b4e47b1d9ad1c0e4be0b98bdc4e7e242" 18:05:35 INFO - } 18:05:35 INFO - ], 18:05:35 INFO - "revision": "031994a3b4e47b1d9ad1c0e4be0b98bdc4e7e242" 18:05:35 INFO - } 18:05:35 INFO - } 18:05:35 INFO - Found installer url https://queue.taskcluster.net/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.dmg. 18:05:35 INFO - Running post-action listener: _resource_record_post_action 18:05:35 INFO - ##### 18:05:35 INFO - ##### Running download-and-extract step. 18:05:35 INFO - ##### 18:05:35 INFO - Running pre-action listener: _resource_record_pre_action 18:05:35 INFO - Running main action method: download_and_extract 18:05:35 INFO - mkdir: /builds/slave/test/build/tests 18:05:35 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')]} 18:05:35 INFO - https://queue.taskcluster.net/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/test_packages.json matches https://queue.taskcluster.net 18:05:35 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/test_packages.json 18:05:35 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/test_packages.json 18:05:35 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/test_packages.json to /builds/slave/test/build/test_packages.json 18:05:35 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/test_packages.json', 'file_name': '/builds/slave/test/build/test_packages.json'}, attempt #1 18:05:38 INFO - Downloaded 1149 bytes. 18:05:38 INFO - Reading from file /builds/slave/test/build/test_packages.json 18:05:38 INFO - Using the following test package requirements: 18:05:38 INFO - {u'common': [u'firefox-45.0a1.en-US.mac.common.tests.zip'], 18:05:38 INFO - u'cppunittest': [u'firefox-45.0a1.en-US.mac.common.tests.zip', 18:05:38 INFO - u'firefox-45.0a1.en-US.mac.cppunittest.tests.zip'], 18:05:38 INFO - u'jittest': [u'firefox-45.0a1.en-US.mac.common.tests.zip', 18:05:38 INFO - u'jsshell-mac.zip'], 18:05:38 INFO - u'mochitest': [u'firefox-45.0a1.en-US.mac.common.tests.zip', 18:05:38 INFO - u'firefox-45.0a1.en-US.mac.mochitest.tests.zip'], 18:05:38 INFO - u'mozbase': [u'firefox-45.0a1.en-US.mac.common.tests.zip'], 18:05:38 INFO - u'reftest': [u'firefox-45.0a1.en-US.mac.common.tests.zip', 18:05:38 INFO - u'firefox-45.0a1.en-US.mac.reftest.tests.zip'], 18:05:38 INFO - u'talos': [u'firefox-45.0a1.en-US.mac.common.tests.zip', 18:05:38 INFO - u'firefox-45.0a1.en-US.mac.talos.tests.zip'], 18:05:38 INFO - u'web-platform': [u'firefox-45.0a1.en-US.mac.common.tests.zip', 18:05:38 INFO - u'firefox-45.0a1.en-US.mac.web-platform.tests.zip'], 18:05:38 INFO - u'webapprt': [u'firefox-45.0a1.en-US.mac.common.tests.zip'], 18:05:38 INFO - u'xpcshell': [u'firefox-45.0a1.en-US.mac.common.tests.zip', 18:05:38 INFO - u'firefox-45.0a1.en-US.mac.xpcshell.tests.zip']} 18:05:38 INFO - Downloading packages: [u'firefox-45.0a1.en-US.mac.common.tests.zip'] for test suite category: common 18:05:38 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')]} 18:05:38 INFO - https://queue.taskcluster.net/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.common.tests.zip matches https://queue.taskcluster.net 18:05:38 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.common.tests.zip 18:05:38 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.common.tests.zip 18:05:38 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.common.tests.zip to /builds/slave/test/build/firefox-45.0a1.en-US.mac.common.tests.zip 18:05:38 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.common.tests.zip', 'file_name': u'/builds/slave/test/build/firefox-45.0a1.en-US.mac.common.tests.zip'}, attempt #1 18:05:39 INFO - Downloaded 17460588 bytes. 18:05:39 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.mac.common.tests.zip'] in /builds/slave/test/build/tests 18:05:39 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.mac.common.tests.zip 18:05:39 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.mac.common.tests.zip'] with output_timeout 1760 18:05:44 INFO - Return code: 0 18:05:44 INFO - Downloading packages: [u'firefox-45.0a1.en-US.mac.common.tests.zip', u'firefox-45.0a1.en-US.mac.talos.tests.zip'] for test suite category: talos 18:05:44 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')]} 18:05:44 INFO - https://queue.taskcluster.net/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.common.tests.zip matches https://queue.taskcluster.net 18:05:44 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.common.tests.zip 18:05:44 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.common.tests.zip 18:05:44 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.common.tests.zip to /builds/slave/test/build/firefox-45.0a1.en-US.mac.common.tests.zip 18:05:44 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.common.tests.zip', 'file_name': u'/builds/slave/test/build/firefox-45.0a1.en-US.mac.common.tests.zip'}, attempt #1 18:05:46 INFO - Downloaded 17460588 bytes. 18:05:46 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.mac.common.tests.zip'] in /builds/slave/test/build/tests 18:05:46 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.mac.common.tests.zip 18:05:46 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.mac.common.tests.zip'] with output_timeout 1760 18:05:52 INFO - Return code: 0 18: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')]} 18:05:52 INFO - https://queue.taskcluster.net/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.talos.tests.zip matches https://queue.taskcluster.net 18:05:52 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.talos.tests.zip 18:05:52 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.talos.tests.zip 18:05:52 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.talos.tests.zip to /builds/slave/test/build/firefox-45.0a1.en-US.mac.talos.tests.zip 18:05:52 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.talos.tests.zip', 'file_name': u'/builds/slave/test/build/firefox-45.0a1.en-US.mac.talos.tests.zip'}, attempt #1 18:05:53 INFO - Downloaded 11131693 bytes. 18:05:53 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.mac.talos.tests.zip'] in /builds/slave/test/build/tests 18:05:53 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.mac.talos.tests.zip 18:05:53 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.mac.talos.tests.zip'] with output_timeout 1760 18:05:54 INFO - Return code: 0 18:05:54 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')]} 18:05:54 INFO - https://queue.taskcluster.net/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.dmg matches https://queue.taskcluster.net 18:05:54 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.dmg 18:05:54 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.dmg 18:05:54 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.dmg to /builds/slave/test/build/firefox-45.0a1.en-US.mac.dmg 18:05:54 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.dmg', 'file_name': '/builds/slave/test/build/firefox-45.0a1.en-US.mac.dmg'}, attempt #1 18:05:59 INFO - Downloaded 108701152 bytes. 18:05:59 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.dmg 18:05:59 INFO - mkdir: /builds/slave/test/properties 18:05:59 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url 18:05:59 INFO - Writing to file /builds/slave/test/properties/build_url 18:05:59 INFO - Contents: 18:05:59 INFO - build_url:https://queue.taskcluster.net/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.dmg 18:05:59 INFO - Running post-action listener: _resource_record_post_action 18:05:59 INFO - Running post-action listener: set_extra_try_arguments 18:05:59 INFO - ##### 18:05:59 INFO - ##### Running populate-webroot step. 18:05:59 INFO - ##### 18:05:59 INFO - Running pre-action listener: _resource_record_pre_action 18:05:59 INFO - Running main action method: populate_webroot 18:05:59 INFO - {'extra_options': {'android': ['--apkPath=%(apk_path)s']}, 18:05:59 INFO - 'mobile-suites': {'remote-tp4m_nochrome': {'tests': ['tp4m']}, 18:05:59 INFO - 'remote-trobocheck2': {'talos_options': ['--fennecIDs', 18:05:59 INFO - '../fennec_ids.txt'], 18:05:59 INFO - 'tests': ['tcheck2']}, 18:05:59 INFO - 'remote-tsvgx': {'talos_options': ['--noChrome', 18:05:59 INFO - '--tppagecycles', 18:05:59 INFO - '7'], 18:05:59 INFO - 'tests': ['tsvgm']}}, 18:05:59 INFO - 'suites': {'chromez': {'tests': ['tresize', 'tcanvasmark']}, 18:05:59 INFO - 'chromez-e10s': {'talos_options': ['--e10s'], 18:05:59 INFO - 'tests': ['tresize', 'tcanvasmark']}, 18:05:59 INFO - 'dromaeojs': {'tests': ['dromaeo_css', 'kraken', 'v8_7']}, 18:05:59 INFO - 'dromaeojs-e10s': {'talos_options': ['--e10s'], 18:05:59 INFO - 'tests': ['dromaeo_css', 'kraken', 'v8_7']}, 18:05:59 INFO - 'g1': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 18:05:59 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 18:05:59 INFO - 'g1-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 18:05:59 INFO - 'talos_options': ['--e10s'], 18:05:59 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 18:05:59 INFO - 'g2': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 18:05:59 INFO - 'tests': ['damp', 'tps']}, 18:05:59 INFO - 'g2-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 18:05:59 INFO - 'talos_options': ['--e10s'], 18:05:59 INFO - 'tests': ['damp', 'tps']}, 18:05:59 INFO - 'g3': {'tests': ['dromaeo_dom']}, 18:05:59 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']}, 18:05:59 INFO - 'other': {'tests': ['a11yr', 18:05:59 INFO - 'ts_paint', 18:05:59 INFO - 'tpaint', 18:05:59 INFO - 'sessionrestore', 18:05:59 INFO - 'sessionrestore_no_auto_restore']}, 18:05:59 INFO - 'other-e10s': {'talos_options': ['--e10s'], 18:05:59 INFO - 'tests': ['a11yr', 18:05:59 INFO - 'ts_paint', 18:05:59 INFO - 'tpaint', 18:05:59 INFO - 'sessionrestore', 18:05:59 INFO - 'sessionrestore_no_auto_restore']}, 18:05:59 INFO - 'other-e10s_l64': {'talos_options': ['--e10s'], 18:05:59 INFO - 'tests': ['a11yr', 18:05:59 INFO - 'ts_paint', 18:05:59 INFO - 'tpaint', 18:05:59 INFO - 'sessionrestore', 18:05:59 INFO - 'sessionrestore_no_auto_restore']}, 18:05:59 INFO - 'other-e10s_nol64': {'talos_options': ['--e10s'], 18:05:59 INFO - 'tests': ['a11yr', 18:05:59 INFO - 'ts_paint', 18:05:59 INFO - 'tpaint', 18:05:59 INFO - 'sessionrestore', 18:05:59 INFO - 'sessionrestore_no_auto_restore']}, 18:05:59 INFO - 'other_l64': {'tests': ['a11yr', 18:05:59 INFO - 'ts_paint', 18:05:59 INFO - 'tpaint', 18:05:59 INFO - 'sessionrestore', 18:05:59 INFO - 'sessionrestore_no_auto_restore']}, 18:05:59 INFO - 'other_nol64': {'tests': ['a11yr', 18:05:59 INFO - 'ts_paint', 18:05:59 INFO - 'tpaint', 18:05:59 INFO - 'sessionrestore', 18:05:59 INFO - 'sessionrestore_no_auto_restore']}, 18:05:59 INFO - 'svgr': {'tests': ['tsvgx', 18:05:59 INFO - 'tsvgr_opacity', 18:05:59 INFO - 'tart', 18:05:59 INFO - 'tscrollx', 18:05:59 INFO - 'cart']}, 18:05:59 INFO - 'svgr-e10s': {'talos_options': ['--e10s'], 18:05:59 INFO - 'tests': ['tsvgx', 18:05:59 INFO - 'tsvgr_opacity', 18:05:59 INFO - 'tart', 18:05:59 INFO - 'tscrollx', 18:05:59 INFO - 'cart']}, 18:05:59 INFO - 'tp5o': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 18:05:59 INFO - 'tests': ['tp5o']}, 18:05:59 INFO - 'tp5o-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 18:05:59 INFO - 'talos_options': ['--e10s'], 18:05:59 INFO - 'tests': ['tp5o']}, 18:05:59 INFO - 'xperf': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 18:05:59 INFO - 'talos_options': ['--xperf_path', 18:05:59 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 18:05:59 INFO - 'tests': ['tp5n']}, 18:05:59 INFO - 'xperf-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 18:05:59 INFO - 'talos_options': ['--e10s', 18:05:59 INFO - '--xperf_path', 18:05:59 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 18:05:59 INFO - 'tests': ['tp5n']}}, 18:05:59 INFO - 'talos.zip': {'path': '', 18:05:59 INFO - 'url': 'http://talos-bundles.pvt.build.mozilla.org/zips/talos.a6052c33d420.zip'}} 18:05:59 INFO - Running post-action listener: _resource_record_post_action 18:05:59 INFO - ##### 18:05:59 INFO - ##### Running create-virtualenv step. 18:05:59 INFO - ##### 18:05:59 INFO - Running pre-action listener: _resource_record_pre_action 18:05:59 INFO - Running main action method: create_virtualenv 18:05:59 INFO - Creating virtualenv /builds/slave/test/build/venv 18:05:59 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 18:05:59 INFO - Copy/paste: /tools/buildbot/bin/python /tools/misc-python/virtualenv.py --no-site-packages --distribute /builds/slave/test/build/venv 18:06:00 INFO - The --no-site-packages flag is deprecated; it is now the default behavior. 18:06:00 INFO - Using real prefix '/tools/python27' 18:06:00 INFO - New python executable in /builds/slave/test/build/venv/bin/python 18:06:01 INFO - Installing distribute.............................................................................................................................................................................................done. 18:06:04 INFO - Installing pip.................done. 18:06:04 INFO - Return code: 0 18:06:04 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv 18:06:04 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')]} 18:06:04 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 18:06:04 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:04 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')]} 18:06:04 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 18:06:04 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:04 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--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 0x10e1a5490>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10e182228>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fad10e01c60>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10e0c89f0>, '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 0x10de28db0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10e0bc8c8>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'XPC_SERVICE_NAME': '0', 'HOME': '/Users/cltbld', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 'NO_EM_RESTART': '1', 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 'XPCOM_DEBUG_BREAK': 'warn', 'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.NpFlPSwRQX/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.u2RYEBHvJR/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/', '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0', 'PWD': '/builds/slave/test', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'PAGER': '/bin/cat'}}, attempt #1 18:06:04 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--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 18:06:04 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --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 18:06:04 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.NpFlPSwRQX/Render', 18:06:04 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 18:06:04 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 18:06:04 INFO - 'HOME': '/Users/cltbld', 18:06:04 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 18:06:04 INFO - 'LOGNAME': 'cltbld', 18:06:04 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 18:06:04 INFO - 'MOZ_NO_REMOTE': '1', 18:06:04 INFO - 'NO_EM_RESTART': '1', 18:06:04 INFO - 'PAGER': '/bin/cat', 18:06:04 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 18:06:04 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 18:06:04 INFO - 'PWD': '/builds/slave/test', 18:06:04 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 18:06:04 INFO - 'SHELL': '/bin/bash', 18:06:04 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.u2RYEBHvJR/Listeners', 18:06:04 INFO - 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/', 18:06:04 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 18:06:04 INFO - 'USER': 'cltbld', 18:06:04 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 18:06:04 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 18:06:04 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 18:06:04 INFO - 'XPC_FLAGS': '0x0', 18:06:04 INFO - 'XPC_SERVICE_NAME': '0', 18:06:04 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'} 18:06:04 INFO - Ignoring indexes: https://pypi.python.org/simple/ 18:06:04 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 18:06:04 INFO - Cleaning up... 18:06:04 INFO - Return code: 0 18:06:04 INFO - Installing psutil>=0.7.1 into virtualenv /builds/slave/test/build/venv 18:06:04 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')]} 18:06:04 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 18:06:04 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:04 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')]} 18:06:04 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 18:06:04 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:04 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--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>=0.7.1']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x10e1a5490>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10e182228>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fad10e01c60>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10e0c89f0>, '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 0x10de28db0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10e0bc8c8>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'XPC_SERVICE_NAME': '0', 'HOME': '/Users/cltbld', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 'NO_EM_RESTART': '1', 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 'XPCOM_DEBUG_BREAK': 'warn', 'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.NpFlPSwRQX/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.u2RYEBHvJR/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/', '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0', 'PWD': '/builds/slave/test', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'PAGER': '/bin/cat'}}, attempt #1 18:06:04 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--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>=0.7.1'] in /builds/slave/test/build 18:06:04 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --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>=0.7.1 18:06:04 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.NpFlPSwRQX/Render', 18:06:04 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 18:06:04 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 18:06:04 INFO - 'HOME': '/Users/cltbld', 18:06:04 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 18:06:04 INFO - 'LOGNAME': 'cltbld', 18:06:04 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 18:06:04 INFO - 'MOZ_NO_REMOTE': '1', 18:06:04 INFO - 'NO_EM_RESTART': '1', 18:06:04 INFO - 'PAGER': '/bin/cat', 18:06:04 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 18:06:04 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 18:06:04 INFO - 'PWD': '/builds/slave/test', 18:06:04 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 18:06:04 INFO - 'SHELL': '/bin/bash', 18:06:04 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.u2RYEBHvJR/Listeners', 18:06:04 INFO - 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/', 18:06:04 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 18:06:04 INFO - 'USER': 'cltbld', 18:06:04 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 18:06:04 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 18:06:04 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 18:06:04 INFO - 'XPC_FLAGS': '0x0', 18:06:04 INFO - 'XPC_SERVICE_NAME': '0', 18:06:04 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'} 18:06:05 INFO - Ignoring indexes: https://pypi.python.org/simple/ 18:06:05 INFO - Downloading/unpacking psutil>=0.7.1 18:06:05 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 18:06:05 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 18:06:05 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 18:06:05 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 18:06:05 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 18:06:05 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 18:06:07 INFO - Creating supposed download cache at /builds/slave/test/build/venv/cache 18:06:07 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fpsutil-3.1.1.tar.gz 18:06:07 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/psutil/setup.py) egg_info for package psutil 18:06:07 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 18:06:07 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 18:06:07 INFO - Installing collected packages: psutil 18:06:07 INFO - Running setup.py install for psutil 18:06:07 INFO - building 'psutil._psutil_osx' extension 18:06:07 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 18:06:09 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 18:06:09 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 18:06:09 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 18:06:09 INFO - building 'psutil._psutil_posix' extension 18:06:09 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 18:06:10 WARNING - psutil/_psutil_posix.c:403:11: warning: implicit declaration of function 'ioctl' is invalid in C99 [-Wimplicit-function-declaration] 18:06:10 INFO - ret = ioctl(sock, SIOCGIFFLAGS, &ifr); 18:06:10 INFO - ^ 18:06:10 INFO - 1 warning generated. 18:06:10 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 18:06:10 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 18:06:10 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 18:06:10 INFO - Successfully installed psutil 18:06:10 INFO - Cleaning up... 18:06:10 INFO - Return code: 0 18:06:10 INFO - Installing mozsystemmonitor==0.0.0 into virtualenv /builds/slave/test/build/venv 18:06:10 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')]} 18:06:10 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 18:06:10 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:10 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')]} 18:06:10 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 18:06:10 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:10 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--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.0.0']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x10e1a5490>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10e182228>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fad10e01c60>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10e0c89f0>, '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 0x10de28db0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10e0bc8c8>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'XPC_SERVICE_NAME': '0', 'HOME': '/Users/cltbld', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 'NO_EM_RESTART': '1', 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 'XPCOM_DEBUG_BREAK': 'warn', 'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.NpFlPSwRQX/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.u2RYEBHvJR/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/', '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0', 'PWD': '/builds/slave/test', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'PAGER': '/bin/cat'}}, attempt #1 18:06:10 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--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.0.0'] in /builds/slave/test/build 18:06:10 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --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.0.0 18:06:10 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.NpFlPSwRQX/Render', 18:06:10 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 18:06:10 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 18:06:10 INFO - 'HOME': '/Users/cltbld', 18:06:10 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 18:06:10 INFO - 'LOGNAME': 'cltbld', 18:06:10 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 18:06:10 INFO - 'MOZ_NO_REMOTE': '1', 18:06:10 INFO - 'NO_EM_RESTART': '1', 18:06:10 INFO - 'PAGER': '/bin/cat', 18:06:10 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 18:06:10 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 18:06:10 INFO - 'PWD': '/builds/slave/test', 18:06:10 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 18:06:10 INFO - 'SHELL': '/bin/bash', 18:06:10 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.u2RYEBHvJR/Listeners', 18:06:10 INFO - 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/', 18:06:10 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 18:06:10 INFO - 'USER': 'cltbld', 18:06:10 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 18:06:10 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 18:06:10 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 18:06:10 INFO - 'XPC_FLAGS': '0x0', 18:06:10 INFO - 'XPC_SERVICE_NAME': '0', 18:06:10 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'} 18:06:10 INFO - Ignoring indexes: https://pypi.python.org/simple/ 18:06:10 INFO - Downloading/unpacking mozsystemmonitor==0.0.0 18:06:10 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 18:06:10 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 18:06:10 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 18:06:10 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 18:06:10 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 18:06:10 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 18:06:13 INFO - Downloading mozsystemmonitor-0.0.tar.gz 18:06:13 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fmozsystemmonitor-0.0.tar.gz 18:06:13 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/mozsystemmonitor/setup.py) egg_info for package mozsystemmonitor 18:06:13 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=0.7.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.0.0) 18:06:13 INFO - Installing collected packages: mozsystemmonitor 18:06:13 INFO - Running setup.py install for mozsystemmonitor 18:06:13 INFO - Successfully installed mozsystemmonitor 18:06:13 INFO - Cleaning up... 18:06:13 INFO - Return code: 0 18:06:13 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv 18:06:13 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')]} 18:06:13 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 18:06:13 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:13 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')]} 18:06:13 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 18:06:13 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:13 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--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 0x10e1a5490>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10e182228>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fad10e01c60>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10e0c89f0>, '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 0x10de28db0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10e0bc8c8>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'XPC_SERVICE_NAME': '0', 'HOME': '/Users/cltbld', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 'NO_EM_RESTART': '1', 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 'XPCOM_DEBUG_BREAK': 'warn', 'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.NpFlPSwRQX/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.u2RYEBHvJR/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/', '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0', 'PWD': '/builds/slave/test', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'PAGER': '/bin/cat'}}, attempt #1 18:06:13 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--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 18:06:13 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --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 18:06:13 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.NpFlPSwRQX/Render', 18:06:13 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 18:06:13 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 18:06:13 INFO - 'HOME': '/Users/cltbld', 18:06:13 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 18:06:13 INFO - 'LOGNAME': 'cltbld', 18:06:13 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 18:06:13 INFO - 'MOZ_NO_REMOTE': '1', 18:06:13 INFO - 'NO_EM_RESTART': '1', 18:06:13 INFO - 'PAGER': '/bin/cat', 18:06:13 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 18:06:13 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 18:06:13 INFO - 'PWD': '/builds/slave/test', 18:06:13 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 18:06:13 INFO - 'SHELL': '/bin/bash', 18:06:13 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.u2RYEBHvJR/Listeners', 18:06:13 INFO - 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/', 18:06:13 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 18:06:13 INFO - 'USER': 'cltbld', 18:06:13 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 18:06:13 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 18:06:13 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 18:06:13 INFO - 'XPC_FLAGS': '0x0', 18:06:13 INFO - 'XPC_SERVICE_NAME': '0', 18:06:13 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'} 18:06:13 INFO - Ignoring indexes: https://pypi.python.org/simple/ 18:06:13 INFO - Downloading/unpacking blobuploader==1.2.4 18:06:13 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 18:06:13 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 18:06:13 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 18:06:13 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 18:06:13 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 18:06:13 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 18:06:16 INFO - Downloading blobuploader-1.2.4.tar.gz 18:06:16 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fblobuploader-1.2.4.tar.gz 18:06:16 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blobuploader/setup.py) egg_info for package blobuploader 18:06:16 INFO - Downloading/unpacking requests==1.2.3. (from blobuploader==1.2.4) 18:06:16 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 18:06:16 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 18:06:16 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 18:06:16 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 18:06:16 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 18:06:16 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 18:06:16 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Frequests-1.2.3.tar.gz 18:06:16 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests 18:06:16 INFO - Downloading/unpacking docopt==0.6.1 (from blobuploader==1.2.4) 18:06:16 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 18:06:16 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 18:06:16 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 18:06:16 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 18:06:16 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 18:06:16 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 18:06:17 INFO - Downloading docopt-0.6.1.tar.gz 18:06:17 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fdocopt-0.6.1.tar.gz 18:06:17 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/docopt/setup.py) egg_info for package docopt 18:06:17 INFO - Installing collected packages: blobuploader, requests, docopt 18:06:17 INFO - Running setup.py install for blobuploader 18:06:17 INFO - changing mode of build/scripts-2.7/blobberc.py from 664 to 775 18:06:17 INFO - changing mode of /builds/slave/test/build/venv/bin/blobberc.py to 775 18:06:17 INFO - Running setup.py install for requests 18:06:18 INFO - Running setup.py install for docopt 18:06:18 INFO - Successfully installed blobuploader requests docopt 18:06:18 INFO - Cleaning up... 18:06:18 INFO - Return code: 0 18:06:18 INFO - Installing None into virtualenv /builds/slave/test/build/venv 18:06:18 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')]} 18:06:18 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 18:06:18 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:18 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')]} 18:06:18 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 18:06:18 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:18 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--download-cache', '/builds/slave/test/build/venv/cache', '--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 0x10e1a5490>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10e182228>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fad10e01c60>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10e0c89f0>, '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 0x10de28db0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10e0bc8c8>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build/tests/config', 'env': {'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'XPC_SERVICE_NAME': '0', 'HOME': '/Users/cltbld', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 'NO_EM_RESTART': '1', 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 'XPCOM_DEBUG_BREAK': 'warn', 'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.NpFlPSwRQX/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.u2RYEBHvJR/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/', '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0', 'PWD': '/builds/slave/test', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'PAGER': '/bin/cat'}}, attempt #1 18:06:18 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--download-cache', '/builds/slave/test/build/venv/cache', '--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 18:06:18 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --no-deps --download-cache /builds/slave/test/build/venv/cache --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 18:06:18 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.NpFlPSwRQX/Render', 18:06:18 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 18:06:18 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 18:06:18 INFO - 'HOME': '/Users/cltbld', 18:06:18 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 18:06:18 INFO - 'LOGNAME': 'cltbld', 18:06:18 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 18:06:18 INFO - 'MOZ_NO_REMOTE': '1', 18:06:18 INFO - 'NO_EM_RESTART': '1', 18:06:18 INFO - 'PAGER': '/bin/cat', 18:06:18 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 18:06:18 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 18:06:18 INFO - 'PWD': '/builds/slave/test', 18:06:18 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 18:06:18 INFO - 'SHELL': '/bin/bash', 18:06:18 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.u2RYEBHvJR/Listeners', 18:06:18 INFO - 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/', 18:06:18 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 18:06:18 INFO - 'USER': 'cltbld', 18:06:18 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 18:06:18 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 18:06:18 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 18:06:18 INFO - 'XPC_FLAGS': '0x0', 18:06:18 INFO - 'XPC_SERVICE_NAME': '0', 18:06:18 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'} 18:06:18 INFO - Ignoring indexes: https://pypi.python.org/simple/ 18:06:18 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 18:06:18 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-qYTTIC-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 18:06:18 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 18:06:18 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-najGwr-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 18:06:18 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 18:06:18 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-EFc20g-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 18:06:18 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 18:06:18 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-_mMWEp-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 18:06:19 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 18:06:19 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-Xc6w_7-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 18:06:19 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 18:06:19 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-8_GSxk-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 18:06:19 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 18:06:19 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-71eiAV-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 18:06:19 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 18:06:19 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-MPGn7Y-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 18:06:19 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 18:06:19 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-8T1_mp-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 18:06:19 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 18:06:19 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-IJ0h9h-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 18:06:19 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 18:06:19 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-zMKRej-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 18:06:19 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 18:06:19 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-9mL9eV-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 18:06:20 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 18:06:20 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-XAPqTi-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 18:06:20 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 18:06:20 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-tJUXqz-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 18:06:20 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 18:06:20 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-b7i2an-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 18:06:20 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 18:06:20 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-vE9mok-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 18:06:20 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 18:06:20 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-ezA_wY-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 18:06:20 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion 18:06:20 INFO - Running setup.py install for manifestparser 18:06:20 INFO - Installing manifestparser script to /builds/slave/test/build/venv/bin 18:06:20 INFO - Running setup.py install for mozcrash 18:06:20 INFO - Running setup.py install for mozdebug 18:06:21 INFO - Running setup.py install for mozdevice 18:06:21 INFO - Installing sutini script to /builds/slave/test/build/venv/bin 18:06:21 INFO - Installing dm script to /builds/slave/test/build/venv/bin 18:06:21 INFO - Running setup.py install for mozfile 18:06:21 INFO - Running setup.py install for mozhttpd 18:06:21 INFO - Installing mozhttpd script to /builds/slave/test/build/venv/bin 18:06:21 INFO - Running setup.py install for mozinfo 18:06:21 INFO - Installing mozinfo script to /builds/slave/test/build/venv/bin 18:06:21 INFO - Running setup.py install for mozInstall 18:06:21 INFO - Installing moz_remove_from_system script to /builds/slave/test/build/venv/bin 18:06:21 INFO - Installing mozuninstall script to /builds/slave/test/build/venv/bin 18:06:21 INFO - Installing mozinstall script to /builds/slave/test/build/venv/bin 18:06:21 INFO - Installing moz_add_to_system script to /builds/slave/test/build/venv/bin 18:06:21 INFO - Running setup.py install for mozleak 18:06:22 INFO - Running setup.py install for mozlog 18:06:22 INFO - Installing structlog script to /builds/slave/test/build/venv/bin 18:06:22 INFO - Running setup.py install for moznetwork 18:06:22 INFO - Installing moznetwork script to /builds/slave/test/build/venv/bin 18:06:22 INFO - Running setup.py install for mozprocess 18:06:22 INFO - Running setup.py install for mozprofile 18:06:22 INFO - Installing mozprofile script to /builds/slave/test/build/venv/bin 18:06:22 INFO - Installing diff-profiles script to /builds/slave/test/build/venv/bin 18:06:22 INFO - Installing view-profile script to /builds/slave/test/build/venv/bin 18:06:22 INFO - Running setup.py install for mozrunner 18:06:23 INFO - Installing mozrunner script to /builds/slave/test/build/venv/bin 18:06:23 INFO - Running setup.py install for mozscreenshot 18:06:23 INFO - Running setup.py install for moztest 18:06:23 INFO - Running setup.py install for mozversion 18:06:23 INFO - Installing mozversion script to /builds/slave/test/build/venv/bin 18:06:23 INFO - Successfully installed manifestparser mozcrash mozdebug mozdevice mozfile mozhttpd mozinfo mozInstall mozleak mozlog moznetwork mozprocess mozprofile mozrunner mozscreenshot moztest mozversion 18:06:23 INFO - Cleaning up... 18:06:23 INFO - Return code: 0 18:06:23 INFO - Installing None into virtualenv /builds/slave/test/build/venv 18:06:23 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')]} 18:06:23 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 18:06:23 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:23 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')]} 18:06:23 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 18:06:23 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:23 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--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 0x10e1a5490>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10e182228>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fad10e01c60>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10e0c89f0>, '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 0x10de28db0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10e0bc8c8>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build/tests/config', 'env': {'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'XPC_SERVICE_NAME': '0', 'HOME': '/Users/cltbld', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 'NO_EM_RESTART': '1', 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 'XPCOM_DEBUG_BREAK': 'warn', 'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.NpFlPSwRQX/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.u2RYEBHvJR/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/', '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0', 'PWD': '/builds/slave/test', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'PAGER': '/bin/cat'}}, attempt #1 18:06:23 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--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 18:06:23 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --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 18:06:23 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.NpFlPSwRQX/Render', 18:06:23 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 18:06:23 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 18:06:23 INFO - 'HOME': '/Users/cltbld', 18:06:23 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 18:06:23 INFO - 'LOGNAME': 'cltbld', 18:06:23 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 18:06:23 INFO - 'MOZ_NO_REMOTE': '1', 18:06:23 INFO - 'NO_EM_RESTART': '1', 18:06:23 INFO - 'PAGER': '/bin/cat', 18:06:23 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 18:06:23 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 18:06:23 INFO - 'PWD': '/builds/slave/test', 18:06:23 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 18:06:23 INFO - 'SHELL': '/bin/bash', 18:06:23 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.u2RYEBHvJR/Listeners', 18:06:23 INFO - 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/', 18:06:23 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 18:06:23 INFO - 'USER': 'cltbld', 18:06:23 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 18:06:23 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 18:06:23 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 18:06:23 INFO - 'XPC_FLAGS': '0x0', 18:06:23 INFO - 'XPC_SERVICE_NAME': '0', 18:06:23 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'} 18:06:23 INFO - Ignoring indexes: https://pypi.python.org/simple/ 18:06:23 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 18:06:23 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-ndFPgc-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 18:06:23 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)) 18:06:23 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 18:06:23 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-Bgo97G-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 18:06:24 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash==0.16 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)) 18:06:24 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 18:06:24 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-fWbjRh-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 18:06:24 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)) 18:06:24 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 18:06:24 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-U0rFWC-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 18:06:24 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdevice==0.47 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)) 18:06:24 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 18:06:24 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-jcWbHa-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 18:06:24 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)) 18:06:24 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 18:06:24 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-m73W3O-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 18:06:24 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)) 18:06:24 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 18:06:24 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-LwzUMJ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 18:06:24 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)) 18:06:24 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 18:06:24 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-WomL6N-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 18:06:24 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)) 18:06:24 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 18:06:24 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-hOqDRL-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 18:06:24 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)) 18:06:24 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 18:06:24 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-zVyB1f-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 18:06:25 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog==3.0 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)) 18:06:25 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 18:06:25 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-VhusZ8-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 18:06:25 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)) 18:06:25 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 18:06:25 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-kfAVD7-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 18:06:25 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess==0.22 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)) 18:06:25 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 18:06:25 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-36_lDj-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 18:06:25 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile==0.27 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)) 18:06:25 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 18:06:25 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-nFfXBC-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 18:06:25 INFO - Requirement already satisfied (use --upgrade to upgrade): mozrunner==6.11 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)) 18:06:25 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 18:06:25 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-QvtsQ1-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 18:06:25 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)) 18:06:25 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 18:06:25 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-rBFYUR-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 18:06:25 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)) 18:06:25 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 18:06:25 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-JEbylz-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 18:06:25 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)) 18:06:25 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.16->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2)) 18:06:25 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.16->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2)) 18:06:25 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)) 18:06:25 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.47->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4)) 18:06:25 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.47->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4)) 18:06:25 INFO - Downloading/unpacking blessings>=1.3 (from mozlog==3.0->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 18:06:25 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 18:06:25 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 18:06:25 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 18:06:25 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 18:06:25 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 18:06:25 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 18:06:28 INFO - Downloading blessings-1.5.1.tar.gz 18:06:28 INFO - Storing download in cache at /builds/slave/test/build/venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fblessings-1.5.1.tar.gz 18:06:28 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blessings/setup.py) egg_info for package blessings 18:06:28 INFO - Installing collected packages: blessings 18:06:28 INFO - Running setup.py install for blessings 18:06:28 INFO - Successfully installed blessings 18:06:28 INFO - Cleaning up... 18:06:28 INFO - Return code: 0 18:06:28 INFO - Done creating virtualenv /builds/slave/test/build/venv. 18:06:28 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 18:06:28 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 18:06:29 INFO - Reading from file tmpfile_stdout 18:06:29 INFO - Current package versions: 18:06:29 INFO - blessings == 1.5.1 18:06:29 INFO - blobuploader == 1.2.4 18:06:29 INFO - docopt == 0.6.1 18:06:29 INFO - manifestparser == 1.1 18:06:29 INFO - mozInstall == 1.12 18:06:29 INFO - mozcrash == 0.16 18:06:29 INFO - mozdebug == 0.1 18:06:29 INFO - mozdevice == 0.47 18:06:29 INFO - mozfile == 1.2 18:06:29 INFO - mozhttpd == 0.7 18:06:29 INFO - mozinfo == 0.9 18:06:29 INFO - mozleak == 0.1 18:06:29 INFO - mozlog == 3.0 18:06:29 INFO - moznetwork == 0.27 18:06:29 INFO - mozprocess == 0.22 18:06:29 INFO - mozprofile == 0.27 18:06:29 INFO - mozrunner == 6.11 18:06:29 INFO - mozscreenshot == 0.1 18:06:29 INFO - mozsystemmonitor == 0.0 18:06:29 INFO - moztest == 0.7 18:06:29 INFO - mozversion == 1.4 18:06:29 INFO - psutil == 3.1.1 18:06:29 INFO - requests == 1.2.3 18:06:29 INFO - wsgiref == 0.1.2 18:06:29 INFO - Installing None into virtualenv /builds/slave/test/build/venv 18:06:29 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')]} 18:06:29 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 18:06:29 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:29 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')]} 18:06:29 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 18:06:29 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:29 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--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 0x10e1a5490>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10e182228>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fad10e01c60>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10e0c89f0>, '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 0x10de28db0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10e0bc8c8>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build/tests/talos', 'env': {'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'XPC_SERVICE_NAME': '0', 'HOME': '/Users/cltbld', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 'NO_EM_RESTART': '1', 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 'XPCOM_DEBUG_BREAK': 'warn', 'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.NpFlPSwRQX/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.u2RYEBHvJR/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/', '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0', 'PWD': '/builds/slave/test', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'PAGER': '/bin/cat'}}, attempt #1 18:06:29 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--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 18:06:29 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --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 18:06:29 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.NpFlPSwRQX/Render', 18:06:29 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 18:06:29 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 18:06:29 INFO - 'HOME': '/Users/cltbld', 18:06:29 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 18:06:29 INFO - 'LOGNAME': 'cltbld', 18:06:29 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 18:06:29 INFO - 'MOZ_NO_REMOTE': '1', 18:06:29 INFO - 'NO_EM_RESTART': '1', 18:06:29 INFO - 'PAGER': '/bin/cat', 18:06:29 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 18:06:29 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 18:06:29 INFO - 'PWD': '/builds/slave/test', 18:06:29 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 18:06:29 INFO - 'SHELL': '/bin/bash', 18:06:29 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.u2RYEBHvJR/Listeners', 18:06:29 INFO - 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/', 18:06:29 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 18:06:29 INFO - 'USER': 'cltbld', 18:06:29 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 18:06:29 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 18:06:29 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 18:06:29 INFO - 'XPC_FLAGS': '0x0', 18:06:29 INFO - 'XPC_SERVICE_NAME': '0', 18:06:29 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'} 18:06:29 INFO - Ignoring indexes: https://pypi.python.org/simple/ 18:06:29 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 1)) 18:06:29 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 2)) 18:06:29 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 3)) 18:06:29 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 4)) 18:06:29 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 5)) 18:06:29 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 6)) 18:06:29 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 7)) 18:06:29 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 8)) 18:06:29 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.15->-r /builds/slave/test/build/tests/talos/requirements.txt (line 1)) 18:06:29 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 3)) 18:06:29 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.0->mozcrash>=0.15->-r /builds/slave/test/build/tests/talos/requirements.txt (line 1)) 18:06:29 INFO - Cleaning up... 18:06:29 INFO - Return code: 0 18:06:29 INFO - Running post-action listener: _resource_record_post_action 18:06:29 INFO - Running post-action listener: _start_resource_monitoring 18:06:29 INFO - Starting resource monitoring. 18:06:29 INFO - ##### 18:06:29 INFO - ##### Running install step. 18:06:29 INFO - ##### 18:06:29 INFO - Running pre-action listener: _resource_record_pre_action 18:06:29 INFO - Running main action method: install 18:06:29 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 18:06:29 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 18:06:29 INFO - Reading from file tmpfile_stdout 18:06:29 INFO - Detecting whether we're running mozinstall >=1.0... 18:06:29 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h'] 18:06:29 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h 18:06:29 INFO - Reading from file tmpfile_stdout 18:06:29 INFO - Output received: 18:06:29 INFO - Usage: mozinstall [options] installer 18:06:29 INFO - Options: 18:06:29 INFO - -h, --help show this help message and exit 18:06:29 INFO - -d DEST, --destination=DEST 18:06:29 INFO - Directory to install application into. [default: 18:06:29 INFO - "/builds/slave/test"] 18:06:29 INFO - --app=APP Application being installed. [default: firefox] 18:06:29 INFO - mkdir: /builds/slave/test/build/application 18:06:29 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '/builds/slave/test/build/firefox-45.0a1.en-US.mac.dmg', '--destination', '/builds/slave/test/build/application'] 18:06:29 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall /builds/slave/test/build/firefox-45.0a1.en-US.mac.dmg --destination /builds/slave/test/build/application 18:07:07 INFO - Reading from file tmpfile_stdout 18:07:07 INFO - Output received: 18:07:07 INFO - /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox 18:07:07 INFO - Running post-action listener: _resource_record_post_action 18:07:07 INFO - ##### 18:07:07 INFO - ##### Running run-tests step. 18:07:07 INFO - ##### 18:07:07 INFO - Running pre-action listener: _resource_record_pre_action 18:07:07 INFO - Running main action method: run_tests 18:07:07 INFO - Running pre test command check_screen_resolution with 'bash -c screenresolution get && screenresolution list && system_profiler SPDisplaysDataType' 18:07:07 INFO - Running command: ['bash', '-c', 'screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'] in /builds/slave/test/build 18:07:07 INFO - Copy/paste: bash -c "screenresolution get && screenresolution list && system_profiler SPDisplaysDataType" 18:07:07 INFO - 2015-11-13 18:07:07.514 screenresolution[1632:7746] starting screenresolution argv=screenresolution get 18:07:07 INFO - 2015-11-13 18:07:07.517 screenresolution[1632:7746] Display 0: 1600x1200x32@60 18:07:07 INFO - 2015-11-13 18:07:07.524 screenresolution[1633:7748] starting screenresolution argv=screenresolution list 18:07:07 INFO - Available Modes on Display 0 18:07:07 INFO - 1600x1200x32@60 1152x870x32@75 1280x1024x32@75 18:07:07 INFO - 1024x768x32@75 1024x768x32@70 1024x768x32@60 18:07:07 INFO - 800x600x32@75 800x600x32@60 640x480x32@75 18:07:07 INFO - 640x480x32@60 1280x1024x32@60 1280x960x32@60 18:07:07 INFO - 1280x960x32@75 1344x1008x32@60 Graphics/Displays: 18:07:07 INFO - Intel HD Graphics 3000: 18:07:07 INFO - Chipset Model: Intel HD Graphics 3000 18:07:07 INFO - Type: GPU 18:07:07 INFO - Bus: Built-In 18:07:07 INFO - VRAM (Total): 512 MB 18:07:07 INFO - VRAM (Dynamic, Max): 10 18:07:07 INFO - Vendor: Intel (0x8086) 18:07:07 INFO - Device ID: 0x0116 18:07:07 INFO - Revision ID: 0x0009 18:07:07 INFO - Displays: 18:07:07 INFO - Display: 18:07:07 INFO - Resolution: 1600 x 1200 @ 60 Hz 18:07:07 INFO - Pixel Depth: 32-Bit Color (ARGB8888) 18:07:07 INFO - Display Serial Number: 1600x1200 60 18:07:07 INFO - Main Display: Yes 18:07:07 INFO - Mirror: Off 18:07:07 INFO - Online: Yes 18:07:07 INFO - Rotation: Supported 18:07:07 INFO - Return code: 0 18:07:07 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version'] 18:07:07 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version 18:07:07 INFO - Python 2.7.3 18:07:07 INFO - Return code: 0 18:07:07 INFO - grabbing minidump binary from tooltool 18:07:07 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')]} 18:07:07 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: {'error_list': [{'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10e0c89f0>, '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 0x10de28db0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10e0bc8c8>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1 18:07:07 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 18:07:07 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 18:07:07 INFO - INFO - File macosx64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache 18:07:07 INFO - Return code: 0 18:07:07 INFO - Chmoding /builds/slave/test/build/macosx64-minidump_stackwalk to 0755 18:07:07 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir 18:07:07 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir 18:07:07 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/macosx64-minidump_stackwalk 18:07:07 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir 18:07:07 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--debug', '--branchName', 'Fx-Team', '--suite', 'other-e10s', '--executablePath', '/builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.crashreporter-symbols.zip', '--title', 't-yosemite-r5-0016', '--webServer', 'localhost'] in /builds/slave/test/build 18:07:07 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/tests/talos/talos/run_tests.py --debug --branchName Fx-Team --suite other-e10s --executablePath /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox --symbolsPath https://queue.taskcluster.net/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.crashreporter-symbols.zip --title t-yosemite-r5-0016 --webServer localhost 18:07:07 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.NpFlPSwRQX/Render', 18:07:07 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 18:07:07 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 18:07:07 INFO - 'HOME': '/Users/cltbld', 18:07:07 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 18:07:07 INFO - 'LOGNAME': 'cltbld', 18:07:07 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 18:07:07 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/macosx64-minidump_stackwalk', 18:07:07 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 18:07:07 INFO - 'MOZ_NO_REMOTE': '1', 18:07:07 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 18:07:07 INFO - 'NO_EM_RESTART': '1', 18:07:07 INFO - 'PAGER': '/bin/cat', 18:07:07 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 18:07:07 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 18:07:07 INFO - 'PWD': '/builds/slave/test', 18:07:07 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 18:07:07 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 18:07:07 INFO - 'SHELL': '/bin/bash', 18:07:07 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.u2RYEBHvJR/Listeners', 18:07:07 INFO - 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/', 18:07:07 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 18:07:07 INFO - 'USER': 'cltbld', 18:07:07 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 18:07:07 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 18:07:07 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 18:07:07 INFO - 'XPC_FLAGS': '0x0', 18:07:07 INFO - 'XPC_SERVICE_NAME': '0', 18:07:07 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'} 18:07:07 INFO - Calling ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--debug', '--branchName', 'Fx-Team', '--suite', 'other-e10s', '--executablePath', '/builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.crashreporter-symbols.zip', '--title', 't-yosemite-r5-0016', '--webServer', 'localhost'] with output_timeout 3600 18:07:08 INFO - mozversion INFO | application_buildid: 20151113165331 18:07:08 INFO - mozversion INFO | application_changeset: 031994a3b4e47b1d9ad1c0e4be0b98bdc4e7e242 18:07:08 INFO - mozversion INFO | application_display_name: Nightly 18:07:08 INFO - mozversion INFO | application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384} 18:07:08 INFO - mozversion INFO | application_name: Firefox 18:07:08 INFO - mozversion INFO | application_remotingname: firefox 18:07:08 INFO - mozversion INFO | application_repository: https://hg.mozilla.org/integration/fx-team 18:07:08 INFO - mozversion INFO | application_vendor: Mozilla 18:07:08 INFO - mozversion INFO | application_version: 45.0a1 18:07:08 INFO - mozversion INFO | platform_buildid: 20151113165331 18:07:08 INFO - mozversion INFO | platform_changeset: 031994a3b4e47b1d9ad1c0e4be0b98bdc4e7e242 18:07:08 INFO - mozversion INFO | platform_repository: https://hg.mozilla.org/integration/fx-team 18:07:08 INFO - mozversion INFO | platform_version: 45.0a1 18:07:08 INFO - 2015-11-13 18:07:08,232 DEBUG : using testdate: 1447466828 18:07:08 INFO - 2015-11-13 18:07:08,232 DEBUG : actual date: 1447466828 18:07:08 INFO - 2015-11-13 18:07:08,241 INFO : starting webserver on 'localhost:49263' 18:07:08 INFO - 2015-11-13 18:07:08,242 INFO : Starting test suite t-yosemite-r5-0016.e 18:07:08 INFO - 2015-11-13 18:07:08,242 INFO : Starting test a11yr 18:07:08 INFO - 2015-11-13 18:07:08,243 DEBUG : operating with platform_type : mac_ 18:07:08 INFO - 2015-11-13 18:07:08,243 INFO : Initialising browser for a11yr test... 18:07:08 INFO - 2015-11-13 18:07:08,258 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpIvpWG3/profile http://localhost:49263/getInfo.html 18:07:12 INFO - 2015-11-13 18:07:12,369 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 18:07:12 INFO - 2015-11-13 18:07:12,369 DEBUG : BROWSER_OUTPUT: colorDepth:24 18:07:12 INFO - 2015-11-13 18:07:12,369 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/689 18:07:12 INFO - 2015-11-13 18:07:12,369 DEBUG : BROWSER_OUTPUT: __metrics 18:07:13 INFO - 2015-11-13 18:07:13,031 INFO : Browser initialized. 18:07:13 INFO - 2015-11-13 18:07:13,031 INFO : Running cycle 1/1 for a11yr test... 18:07:13 INFO - 2015-11-13 18:07:13,031 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpIvpWG3/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/a11y/a11y.manifest.develop -tpchrome -tpmozafterpaint -tpnoisy -tpcycles 1 -tppagecycles 25 18:07:25 INFO - 2015-11-13 18:07:25,071 DEBUG : BROWSER_OUTPUT: RSS: Main: 239910912 18:07:25 INFO - 2015-11-13 18:07:25,072 DEBUG : BROWSER_OUTPUT: 18:07:26 INFO - 2015-11-13 18:07:26,028 DEBUG : BROWSER_OUTPUT: Cycle 1(1): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 18:07:26 INFO - 2015-11-13 18:07:26,654 DEBUG : BROWSER_OUTPUT: RSS: Main: 264622080 18:07:26 INFO - 2015-11-13 18:07:26,655 DEBUG : BROWSER_OUTPUT: 18:07:27 INFO - 2015-11-13 18:07:27,712 DEBUG : BROWSER_OUTPUT: Cycle 1(2): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 18:07:28 INFO - 2015-11-13 18:07:28,392 DEBUG : BROWSER_OUTPUT: RSS: Main: 280244224 18:07:28 INFO - 2015-11-13 18:07:28,392 DEBUG : BROWSER_OUTPUT: 18:07:29 INFO - 2015-11-13 18:07:29,390 DEBUG : BROWSER_OUTPUT: Cycle 1(3): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 18:07:30 INFO - 2015-11-13 18:07:30,081 DEBUG : BROWSER_OUTPUT: RSS: Main: 293699584 18:07:30 INFO - 2015-11-13 18:07:30,081 DEBUG : BROWSER_OUTPUT: 18:07:31 INFO - 2015-11-13 18:07:31,161 DEBUG : BROWSER_OUTPUT: Cycle 1(4): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 18:07:31 INFO - 2015-11-13 18:07:31,855 DEBUG : BROWSER_OUTPUT: RSS: Main: 294043648 18:07:31 INFO - 2015-11-13 18:07:31,855 DEBUG : BROWSER_OUTPUT: 18:07:33 INFO - 2015-11-13 18:07:33,082 DEBUG : BROWSER_OUTPUT: Cycle 1(5): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 18:07:33 INFO - 2015-11-13 18:07:33,758 DEBUG : BROWSER_OUTPUT: RSS: Main: 294199296 18:07:33 INFO - 2015-11-13 18:07:33,758 DEBUG : BROWSER_OUTPUT: 18:07:34 INFO - 2015-11-13 18:07:34,812 DEBUG : BROWSER_OUTPUT: Cycle 1(6): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 18:07:35 INFO - 2015-11-13 18:07:35,501 DEBUG : BROWSER_OUTPUT: RSS: Main: 295055360 18:07:35 INFO - 2015-11-13 18:07:35,501 DEBUG : BROWSER_OUTPUT: 18:07:36 INFO - 2015-11-13 18:07:36,578 DEBUG : BROWSER_OUTPUT: Cycle 1(7): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 18:07:37 INFO - 2015-11-13 18:07:37,285 DEBUG : BROWSER_OUTPUT: RSS: Main: 295358464 18:07:37 INFO - 2015-11-13 18:07:37,285 DEBUG : BROWSER_OUTPUT: 18:07:38 INFO - 2015-11-13 18:07:38,346 DEBUG : BROWSER_OUTPUT: Cycle 1(8): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 18:07:39 INFO - 2015-11-13 18:07:39,033 DEBUG : BROWSER_OUTPUT: RSS: Main: 295325696 18:07:39 INFO - 2015-11-13 18:07:39,033 DEBUG : BROWSER_OUTPUT: 18:07:40 INFO - 2015-11-13 18:07:40,118 DEBUG : BROWSER_OUTPUT: Cycle 1(9): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 18:07:40 INFO - 2015-11-13 18:07:40,802 DEBUG : BROWSER_OUTPUT: RSS: Main: 295317504 18:07:40 INFO - 2015-11-13 18:07:40,802 DEBUG : BROWSER_OUTPUT: 18:07:41 INFO - 2015-11-13 18:07:41,876 DEBUG : BROWSER_OUTPUT: Cycle 1(10): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 18:07:42 INFO - 2015-11-13 18:07:42,567 DEBUG : BROWSER_OUTPUT: RSS: Main: 295354368 18:07:42 INFO - 2015-11-13 18:07:42,568 DEBUG : BROWSER_OUTPUT: 18:07:43 INFO - 2015-11-13 18:07:43,638 DEBUG : BROWSER_OUTPUT: Cycle 1(11): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 18:07:44 INFO - 2015-11-13 18:07:44,328 DEBUG : BROWSER_OUTPUT: RSS: Main: 295403520 18:07:44 INFO - 2015-11-13 18:07:44,328 DEBUG : BROWSER_OUTPUT: 18:07:45 INFO - 2015-11-13 18:07:45,370 DEBUG : BROWSER_OUTPUT: Cycle 1(12): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 18:07:46 INFO - 2015-11-13 18:07:46,059 DEBUG : BROWSER_OUTPUT: RSS: Main: 295362560 18:07:46 INFO - 2015-11-13 18:07:46,060 DEBUG : BROWSER_OUTPUT: 18:07:47 INFO - 2015-11-13 18:07:47,121 DEBUG : BROWSER_OUTPUT: Cycle 1(13): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 18:07:47 INFO - 2015-11-13 18:07:47,811 DEBUG : BROWSER_OUTPUT: RSS: Main: 295337984 18:07:47 INFO - 2015-11-13 18:07:47,811 DEBUG : BROWSER_OUTPUT: 18:07:48 INFO - 2015-11-13 18:07:48,890 DEBUG : BROWSER_OUTPUT: Cycle 1(14): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 18:07:49 INFO - 2015-11-13 18:07:49,570 DEBUG : BROWSER_OUTPUT: RSS: Main: 295522304 18:07:49 INFO - 2015-11-13 18:07:49,570 DEBUG : BROWSER_OUTPUT: 18:07:50 INFO - 2015-11-13 18:07:50,619 DEBUG : BROWSER_OUTPUT: Cycle 1(15): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 18:07:51 INFO - 2015-11-13 18:07:51,310 DEBUG : BROWSER_OUTPUT: RSS: Main: 296312832 18:07:51 INFO - 2015-11-13 18:07:51,310 DEBUG : BROWSER_OUTPUT: 18:07:52 INFO - 2015-11-13 18:07:52,374 DEBUG : BROWSER_OUTPUT: Cycle 1(16): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 18:07:53 INFO - 2015-11-13 18:07:53,059 DEBUG : BROWSER_OUTPUT: RSS: Main: 295497728 18:07:53 INFO - 2015-11-13 18:07:53,059 DEBUG : BROWSER_OUTPUT: 18:07:54 INFO - 2015-11-13 18:07:54,274 DEBUG : BROWSER_OUTPUT: Cycle 1(17): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 18:07:54 INFO - 2015-11-13 18:07:54,947 DEBUG : BROWSER_OUTPUT: RSS: Main: 295399424 18:07:54 INFO - 2015-11-13 18:07:54,947 DEBUG : BROWSER_OUTPUT: 18:07:56 INFO - 2015-11-13 18:07:56,005 DEBUG : BROWSER_OUTPUT: Cycle 1(18): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 18:07:56 INFO - 2015-11-13 18:07:56,693 DEBUG : BROWSER_OUTPUT: RSS: Main: 295432192 18:07:56 INFO - 2015-11-13 18:07:56,693 DEBUG : BROWSER_OUTPUT: 18:07:57 INFO - 2015-11-13 18:07:57,764 DEBUG : BROWSER_OUTPUT: Cycle 1(19): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 18:07:58 INFO - 2015-11-13 18:07:58,454 DEBUG : BROWSER_OUTPUT: RSS: Main: 295432192 18:07:58 INFO - 2015-11-13 18:07:58,455 DEBUG : BROWSER_OUTPUT: 18:07:59 INFO - 2015-11-13 18:07:59,520 DEBUG : BROWSER_OUTPUT: Cycle 1(20): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 18:08:00 INFO - 2015-11-13 18:08:00,203 DEBUG : BROWSER_OUTPUT: RSS: Main: 295428096 18:08:00 INFO - 2015-11-13 18:08:00,203 DEBUG : BROWSER_OUTPUT: 18:08:01 INFO - 2015-11-13 18:08:01,265 DEBUG : BROWSER_OUTPUT: Cycle 1(21): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 18:08:01 INFO - 2015-11-13 18:08:01,951 DEBUG : BROWSER_OUTPUT: RSS: Main: 295448576 18:08:01 INFO - 2015-11-13 18:08:01,952 DEBUG : BROWSER_OUTPUT: 18:08:03 INFO - 2015-11-13 18:08:03,014 DEBUG : BROWSER_OUTPUT: Cycle 1(22): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 18:08:03 INFO - 2015-11-13 18:08:03,706 DEBUG : BROWSER_OUTPUT: RSS: Main: 295411712 18:08:03 INFO - 2015-11-13 18:08:03,706 DEBUG : BROWSER_OUTPUT: 18:08:04 INFO - 2015-11-13 18:08:04,766 DEBUG : BROWSER_OUTPUT: Cycle 1(23): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 18:08:05 INFO - 2015-11-13 18:08:05,461 DEBUG : BROWSER_OUTPUT: RSS: Main: 295591936 18:08:05 INFO - 2015-11-13 18:08:05,462 DEBUG : BROWSER_OUTPUT: 18:08:06 INFO - 2015-11-13 18:08:06,522 DEBUG : BROWSER_OUTPUT: Cycle 1(24): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 18:08:07 INFO - 2015-11-13 18:08:07,208 DEBUG : BROWSER_OUTPUT: RSS: Main: 295485440 18:08:07 INFO - 2015-11-13 18:08:07,208 DEBUG : BROWSER_OUTPUT: 18:08:08 INFO - 2015-11-13 18:08:08,267 DEBUG : BROWSER_OUTPUT: Cycle 1(25): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 18:08:08 INFO - 2015-11-13 18:08:08,953 DEBUG : BROWSER_OUTPUT: RSS: Main: 295526400 18:08:08 INFO - 2015-11-13 18:08:08,953 DEBUG : BROWSER_OUTPUT: 18:08:09 INFO - 2015-11-13 18:08:09,778 DEBUG : BROWSER_OUTPUT: Cycle 1(1): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 18:08:10 INFO - 2015-11-13 18:08:10,352 DEBUG : BROWSER_OUTPUT: RSS: Main: 293298176 18:08:10 INFO - 2015-11-13 18:08:10,352 DEBUG : BROWSER_OUTPUT: 18:08:11 INFO - 2015-11-13 18:08:11,091 DEBUG : BROWSER_OUTPUT: Cycle 1(2): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 18:08:11 INFO - 2015-11-13 18:08:11,681 DEBUG : BROWSER_OUTPUT: RSS: Main: 292073472 18:08:11 INFO - 2015-11-13 18:08:11,681 DEBUG : BROWSER_OUTPUT: 18:08:12 INFO - 2015-11-13 18:08:12,404 DEBUG : BROWSER_OUTPUT: Cycle 1(3): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 18:08:12 INFO - 2015-11-13 18:08:12,989 DEBUG : BROWSER_OUTPUT: RSS: Main: 293539840 18:08:12 INFO - 2015-11-13 18:08:12,989 DEBUG : BROWSER_OUTPUT: 18:08:13 INFO - 2015-11-13 18:08:13,744 DEBUG : BROWSER_OUTPUT: Cycle 1(4): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 18:08:14 INFO - 2015-11-13 18:08:14,349 DEBUG : BROWSER_OUTPUT: RSS: Main: 296173568 18:08:14 INFO - 2015-11-13 18:08:14,349 DEBUG : BROWSER_OUTPUT: 18:08:14 INFO - 2015-11-13 18:08:14,964 DEBUG : BROWSER_OUTPUT: 1447466894962 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] 18:08:15 INFO - 2015-11-13 18:08:15,087 DEBUG : BROWSER_OUTPUT: Cycle 1(5): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 18:08:15 INFO - 2015-11-13 18:08:15,697 DEBUG : BROWSER_OUTPUT: RSS: Main: 296521728 18:08:15 INFO - 2015-11-13 18:08:15,697 DEBUG : BROWSER_OUTPUT: 18:08:16 INFO - 2015-11-13 18:08:16,436 DEBUG : BROWSER_OUTPUT: Cycle 1(6): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 18:08:17 INFO - 2015-11-13 18:08:17,030 DEBUG : BROWSER_OUTPUT: RSS: Main: 295194624 18:08:17 INFO - 2015-11-13 18:08:17,031 DEBUG : BROWSER_OUTPUT: 18:08:17 INFO - 2015-11-13 18:08:17,763 DEBUG : BROWSER_OUTPUT: Cycle 1(7): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 18:08:18 INFO - 2015-11-13 18:08:18,358 DEBUG : BROWSER_OUTPUT: RSS: Main: 294395904 18:08:18 INFO - 2015-11-13 18:08:18,359 DEBUG : BROWSER_OUTPUT: 18:08:19 INFO - 2015-11-13 18:08:19,089 DEBUG : BROWSER_OUTPUT: Cycle 1(8): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 18:08:19 INFO - 2015-11-13 18:08:19,684 DEBUG : BROWSER_OUTPUT: RSS: Main: 296341504 18:08:19 INFO - 2015-11-13 18:08:19,684 DEBUG : BROWSER_OUTPUT: 18:08:20 INFO - 2015-11-13 18:08:20,410 DEBUG : BROWSER_OUTPUT: Cycle 1(9): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 18:08:21 INFO - 2015-11-13 18:08:21,004 DEBUG : BROWSER_OUTPUT: RSS: Main: 296136704 18:08:21 INFO - 2015-11-13 18:08:21,004 DEBUG : BROWSER_OUTPUT: 18:08:21 INFO - 2015-11-13 18:08:21,753 DEBUG : BROWSER_OUTPUT: Cycle 1(10): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 18:08:22 INFO - 2015-11-13 18:08:22,339 DEBUG : BROWSER_OUTPUT: RSS: Main: 296091648 18:08:22 INFO - 2015-11-13 18:08:22,340 DEBUG : BROWSER_OUTPUT: 18:08:23 INFO - 2015-11-13 18:08:23,066 DEBUG : BROWSER_OUTPUT: Cycle 1(11): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 18:08:23 INFO - 2015-11-13 18:08:23,662 DEBUG : BROWSER_OUTPUT: RSS: Main: 296214528 18:08:23 INFO - 2015-11-13 18:08:23,662 DEBUG : BROWSER_OUTPUT: 18:08:24 INFO - 2015-11-13 18:08:24,387 DEBUG : BROWSER_OUTPUT: Cycle 1(12): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 18:08:24 INFO - 2015-11-13 18:08:24,982 DEBUG : BROWSER_OUTPUT: RSS: Main: 289427456 18:08:24 INFO - 2015-11-13 18:08:24,982 DEBUG : BROWSER_OUTPUT: 18:08:25 INFO - 2015-11-13 18:08:25,721 DEBUG : BROWSER_OUTPUT: Cycle 1(13): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 18:08:26 INFO - 2015-11-13 18:08:26,312 DEBUG : BROWSER_OUTPUT: RSS: Main: 290906112 18:08:26 INFO - 2015-11-13 18:08:26,312 DEBUG : BROWSER_OUTPUT: 18:08:27 INFO - 2015-11-13 18:08:27,042 DEBUG : BROWSER_OUTPUT: Cycle 1(14): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 18:08:27 INFO - 2015-11-13 18:08:27,633 DEBUG : BROWSER_OUTPUT: RSS: Main: 290951168 18:08:27 INFO - 2015-11-13 18:08:27,633 DEBUG : BROWSER_OUTPUT: 18:08:28 INFO - 2015-11-13 18:08:28,359 DEBUG : BROWSER_OUTPUT: Cycle 1(15): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 18:08:28 INFO - 2015-11-13 18:08:28,949 DEBUG : BROWSER_OUTPUT: RSS: Main: 290947072 18:08:28 INFO - 2015-11-13 18:08:28,949 DEBUG : BROWSER_OUTPUT: 18:08:29 INFO - 2015-11-13 18:08:29,681 DEBUG : BROWSER_OUTPUT: Cycle 1(16): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 18:08:30 INFO - 2015-11-13 18:08:30,268 DEBUG : BROWSER_OUTPUT: RSS: Main: 290963456 18:08:30 INFO - 2015-11-13 18:08:30,268 DEBUG : BROWSER_OUTPUT: 18:08:30 INFO - 2015-11-13 18:08:30,994 DEBUG : BROWSER_OUTPUT: Cycle 1(17): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 18:08:31 INFO - 2015-11-13 18:08:31,580 DEBUG : BROWSER_OUTPUT: RSS: Main: 290983936 18:08:31 INFO - 2015-11-13 18:08:31,580 DEBUG : BROWSER_OUTPUT: 18:08:32 INFO - 2015-11-13 18:08:32,309 DEBUG : BROWSER_OUTPUT: Cycle 1(18): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 18:08:32 INFO - 2015-11-13 18:08:32,901 DEBUG : BROWSER_OUTPUT: RSS: Main: 290955264 18:08:32 INFO - 2015-11-13 18:08:32,901 DEBUG : BROWSER_OUTPUT: 18:08:33 INFO - 2015-11-13 18:08:33,629 DEBUG : BROWSER_OUTPUT: Cycle 1(19): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 18:08:34 INFO - 2015-11-13 18:08:34,216 DEBUG : BROWSER_OUTPUT: RSS: Main: 291078144 18:08:34 INFO - 2015-11-13 18:08:34,216 DEBUG : BROWSER_OUTPUT: 18:08:34 INFO - 2015-11-13 18:08:34,944 DEBUG : BROWSER_OUTPUT: Cycle 1(20): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 18:08:35 INFO - 2015-11-13 18:08:35,531 DEBUG : BROWSER_OUTPUT: RSS: Main: 291016704 18:08:35 INFO - 2015-11-13 18:08:35,531 DEBUG : BROWSER_OUTPUT: 18:08:36 INFO - 2015-11-13 18:08:36,262 DEBUG : BROWSER_OUTPUT: Cycle 1(21): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 18:08:36 INFO - 2015-11-13 18:08:36,853 DEBUG : BROWSER_OUTPUT: RSS: Main: 291016704 18:08:36 INFO - 2015-11-13 18:08:36,853 DEBUG : BROWSER_OUTPUT: 18:08:37 INFO - 2015-11-13 18:08:37,600 DEBUG : BROWSER_OUTPUT: Cycle 1(22): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 18:08:38 INFO - 2015-11-13 18:08:38,191 DEBUG : BROWSER_OUTPUT: RSS: Main: 291000320 18:08:38 INFO - 2015-11-13 18:08:38,192 DEBUG : BROWSER_OUTPUT: 18:08:38 INFO - 2015-11-13 18:08:38,897 DEBUG : BROWSER_OUTPUT: Cycle 1(23): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 18:08:39 INFO - 2015-11-13 18:08:39,487 DEBUG : BROWSER_OUTPUT: RSS: Main: 291008512 18:08:39 INFO - 2015-11-13 18:08:39,487 DEBUG : BROWSER_OUTPUT: 18:08:40 INFO - 2015-11-13 18:08:40,226 DEBUG : BROWSER_OUTPUT: Cycle 1(24): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 18:08:40 INFO - 2015-11-13 18:08:40,818 DEBUG : BROWSER_OUTPUT: RSS: Main: 291024896 18:08:40 INFO - 2015-11-13 18:08:40,819 DEBUG : BROWSER_OUTPUT: 18:08:41 INFO - 2015-11-13 18:08:41,554 DEBUG : BROWSER_OUTPUT: Cycle 1(25): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 18:08:41 INFO - 2015-11-13 18:08:41,812 DEBUG : BROWSER_OUTPUT: RSS: Main: 289751040 18:08:41 INFO - 2015-11-13 18:08:41,812 DEBUG : BROWSER_OUTPUT: 18:08:41 INFO - 2015-11-13 18:08:41,812 DEBUG : BROWSER_OUTPUT: __start_tp_report 18:08:41 INFO - 2015-11-13 18:08:41,812 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load 18:08:41 INFO - 2015-11-13 18:08:41,812 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load_details 18:08:41 INFO - 2015-11-13 18:08:41,812 DEBUG : BROWSER_OUTPUT: |i|pagename|runs| 18:08:41 INFO - 2015-11-13 18:08:41,812 DEBUG : BROWSER_OUTPUT: |0;dhtml.html;936;973;954;1017;1157;993;1013;1000;1013;1005;1006;984;1004;1007;1001;1003;1146;988;997;996;1000;1001;1002;999;997 18:08:41 INFO - 2015-11-13 18:08:41,812 DEBUG : BROWSER_OUTPUT: |1;tablemutation.html;301;289;289;300;303;301;290;288;286;289;292;287;299;292;291;290;287;290;290;290;290;292;291;290;293 18:08:41 INFO - 2015-11-13 18:08:41,812 DEBUG : BROWSER_OUTPUT: __end_tp_report 18:08:41 INFO - 2015-11-13 18:08:41,813 DEBUG : BROWSER_OUTPUT: __start_cc_report 18:08:41 INFO - 2015-11-13 18:08:41,813 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_cycle_collect,2569 18:08:41 INFO - 2015-11-13 18:08:41,813 DEBUG : BROWSER_OUTPUT: __end_cc_report 18:08:41 INFO - 2015-11-13 18:08:41,813 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466921808__endTimestamp 18:08:41 INFO - 2015-11-13 18:08:41,813 DEBUG : BROWSER_OUTPUT: 18:08:41 INFO - 2015-11-13 18:08:41,813 DEBUG : BROWSER_OUTPUT: ------- Summary: start ------- 18:08:41 INFO - 2015-11-13 18:08:41,813 DEBUG : BROWSER_OUTPUT: Number of tests: 2 18:08:41 INFO - 2015-11-13 18:08:41,813 DEBUG : BROWSER_OUTPUT: 18:08:41 INFO - 2015-11-13 18:08:41,813 DEBUG : BROWSER_OUTPUT: [#0] dhtml.html Cycles:25 Average:1007.68 Median:1017.00 stddev:46.85 (4.6%) stddev-sans-first:45.36 18:08:41 INFO - 2015-11-13 18:08:41,813 DEBUG : BROWSER_OUTPUT: Values: 936.0 973.0 954.0 1017.0 1157.0 993.0 1013.0 1000.0 1013.0 1005.0 1006.0 984.0 1004.0 1007.0 1001.0 1003.0 1146.0 988.0 997.0 996.0 1000.0 1001.0 1002.0 999.0 997.0 18:08:41 INFO - 2015-11-13 18:08:41,813 DEBUG : BROWSER_OUTPUT: 18:08:41 INFO - 2015-11-13 18:08:41,814 DEBUG : BROWSER_OUTPUT: [#1] tablemutation.html Cycles:25 Average:292.00 Median:290.00 stddev:4.81 (1.7%) stddev-sans-first:4.53 18:08:41 INFO - 2015-11-13 18:08:41,814 DEBUG : BROWSER_OUTPUT: Values: 301.0 289.0 289.0 300.0 303.0 301.0 290.0 288.0 286.0 289.0 292.0 287.0 299.0 292.0 291.0 290.0 287.0 290.0 290.0 290.0 290.0 292.0 291.0 290.0 293.0 18:08:41 INFO - 2015-11-13 18:08:41,814 DEBUG : BROWSER_OUTPUT: -------- Summary: end -------- 18:08:41 INFO - 2015-11-13 18:08:41,814 DEBUG : BROWSER_OUTPUT: 18:08:42 INFO - 2015-11-13 18:08:42,233 INFO : Browser exited with error code: 0 18:08:42 INFO - 2015-11-13 18:08:42,255 INFO : Completed test a11yr (00:01:34) 18:08:42 INFO - 2015-11-13 18:08:42,255 INFO : Starting test ts_paint 18:08:42 INFO - 2015-11-13 18:08:42,255 DEBUG : operating with platform_type : mac_ 18:08:42 INFO - 2015-11-13 18:08:42,255 INFO : Initialising browser for ts_paint test... 18:08:42 INFO - 2015-11-13 18:08:42,268 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpahoh0b/profile http://localhost:49263/getInfo.html 18:08:45 INFO - 2015-11-13 18:08:45,177 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 18:08:45 INFO - 2015-11-13 18:08:45,177 DEBUG : BROWSER_OUTPUT: colorDepth:24 18:08:45 INFO - 2015-11-13 18:08:45,177 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/689 18:08:45 INFO - 2015-11-13 18:08:45,177 DEBUG : BROWSER_OUTPUT: __metrics 18:08:45 INFO - 2015-11-13 18:08:45,786 INFO : Browser initialized. 18:08:45 INFO - 2015-11-13 18:08:45,786 INFO : Running cycle 1/20 for ts_paint test... 18:08:45 INFO - 2015-11-13 18:08:45,786 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpahoh0b/profile http://localhost:49263/startup_test/tspaint_test.html 18:08:48 INFO - 2015-11-13 18:08:48,216 DEBUG : BROWSER_OUTPUT: __start_report699__end_report 18:08:48 INFO - 2015-11-13 18:08:48,216 DEBUG : BROWSER_OUTPUT: 18:08:48 INFO - 2015-11-13 18:08:48,217 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466928214__endTimestamp 18:08:48 INFO - 2015-11-13 18:08:48,892 INFO : Browser exited with error code: 0 18:08:48 INFO - 2015-11-13 18:08:48,893 INFO : Running cycle 2/20 for ts_paint test... 18:08:48 INFO - 2015-11-13 18:08:48,894 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpahoh0b/profile http://localhost:49263/startup_test/tspaint_test.html 18:08:50 INFO - 2015-11-13 18:08:50,878 DEBUG : BROWSER_OUTPUT: __start_report746__end_report 18:08:50 INFO - 2015-11-13 18:08:50,878 DEBUG : BROWSER_OUTPUT: 18:08:50 INFO - 2015-11-13 18:08:50,885 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466930883__endTimestamp 18:08:51 INFO - 2015-11-13 18:08:51,475 INFO : Browser exited with error code: 0 18:08:51 INFO - 2015-11-13 18:08:51,477 INFO : Running cycle 3/20 for ts_paint test... 18:08:51 INFO - 2015-11-13 18:08:51,477 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpahoh0b/profile http://localhost:49263/startup_test/tspaint_test.html 18:08:53 INFO - 2015-11-13 18:08:53,464 DEBUG : BROWSER_OUTPUT: __start_report726__end_report 18:08:53 INFO - 2015-11-13 18:08:53,464 DEBUG : BROWSER_OUTPUT: 18:08:53 INFO - 2015-11-13 18:08:53,466 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466933465__endTimestamp 18:08:54 INFO - 2015-11-13 18:08:54,078 INFO : Browser exited with error code: 0 18:08:54 INFO - 2015-11-13 18:08:54,079 INFO : Running cycle 4/20 for ts_paint test... 18:08:54 INFO - 2015-11-13 18:08:54,079 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpahoh0b/profile http://localhost:49263/startup_test/tspaint_test.html 18:08:56 INFO - 2015-11-13 18:08:56,061 DEBUG : BROWSER_OUTPUT: __start_report727__end_report 18:08:56 INFO - 2015-11-13 18:08:56,061 DEBUG : BROWSER_OUTPUT: 18:08:56 INFO - 2015-11-13 18:08:56,069 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466936065__endTimestamp 18:08:56 INFO - 2015-11-13 18:08:56,740 INFO : Browser exited with error code: 0 18:08:56 INFO - 2015-11-13 18:08:56,742 INFO : Running cycle 5/20 for ts_paint test... 18:08:56 INFO - 2015-11-13 18:08:56,742 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpahoh0b/profile http://localhost:49263/startup_test/tspaint_test.html 18:08:58 INFO - 2015-11-13 18:08:58,733 DEBUG : BROWSER_OUTPUT: __start_report724__end_report 18:08:58 INFO - 2015-11-13 18:08:58,734 DEBUG : BROWSER_OUTPUT: 18:08:58 INFO - 2015-11-13 18:08:58,734 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466938732__endTimestamp 18:08:59 INFO - 2015-11-13 18:08:59,407 INFO : Browser exited with error code: 0 18:08:59 INFO - 2015-11-13 18:08:59,409 INFO : Running cycle 6/20 for ts_paint test... 18:08:59 INFO - 2015-11-13 18:08:59,409 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpahoh0b/profile http://localhost:49263/startup_test/tspaint_test.html 18:09:01 INFO - 2015-11-13 18:09:01,396 DEBUG : BROWSER_OUTPUT: __start_report710__end_report 18:09:01 INFO - 2015-11-13 18:09:01,396 DEBUG : BROWSER_OUTPUT: 18:09:01 INFO - 2015-11-13 18:09:01,400 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466941399__endTimestamp 18:09:02 INFO - 2015-11-13 18:09:02,077 INFO : Browser exited with error code: 0 18:09:02 INFO - 2015-11-13 18:09:02,079 INFO : Running cycle 7/20 for ts_paint test... 18:09:02 INFO - 2015-11-13 18:09:02,079 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpahoh0b/profile http://localhost:49263/startup_test/tspaint_test.html 18:09:04 INFO - 2015-11-13 18:09:04,063 DEBUG : BROWSER_OUTPUT: __start_report725__end_report 18:09:04 INFO - 2015-11-13 18:09:04,063 DEBUG : BROWSER_OUTPUT: 18:09:04 INFO - 2015-11-13 18:09:04,067 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466944066__endTimestamp 18:09:04 INFO - 2015-11-13 18:09:04,765 INFO : Browser exited with error code: 0 18:09:04 INFO - 2015-11-13 18:09:04,766 INFO : Running cycle 8/20 for ts_paint test... 18:09:04 INFO - 2015-11-13 18:09:04,766 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpahoh0b/profile http://localhost:49263/startup_test/tspaint_test.html 18:09:06 INFO - 2015-11-13 18:09:06,784 DEBUG : BROWSER_OUTPUT: __start_report726__end_report 18:09:06 INFO - 2015-11-13 18:09:06,784 DEBUG : BROWSER_OUTPUT: 18:09:06 INFO - 2015-11-13 18:09:06,785 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466946782__endTimestamp 18:09:07 INFO - 2015-11-13 18:09:07,483 INFO : Browser exited with error code: 0 18:09:07 INFO - 2015-11-13 18:09:07,485 INFO : Running cycle 9/20 for ts_paint test... 18:09:07 INFO - 2015-11-13 18:09:07,485 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpahoh0b/profile http://localhost:49263/startup_test/tspaint_test.html 18:09:09 INFO - 2015-11-13 18:09:09,483 DEBUG : BROWSER_OUTPUT: __start_report724__end_report 18:09:09 INFO - 2015-11-13 18:09:09,484 DEBUG : BROWSER_OUTPUT: 18:09:09 INFO - 2015-11-13 18:09:09,484 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466949482__endTimestamp 18:09:10 INFO - 2015-11-13 18:09:10,203 INFO : Browser exited with error code: 0 18:09:10 INFO - 2015-11-13 18:09:10,204 INFO : Running cycle 10/20 for ts_paint test... 18:09:10 INFO - 2015-11-13 18:09:10,204 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpahoh0b/profile http://localhost:49263/startup_test/tspaint_test.html 18:09:12 INFO - 2015-11-13 18:09:12,182 DEBUG : BROWSER_OUTPUT: __start_report709__end_report 18:09:12 INFO - 2015-11-13 18:09:12,183 DEBUG : BROWSER_OUTPUT: 18:09:12 INFO - 2015-11-13 18:09:12,183 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466952182__endTimestamp 18:09:12 INFO - 2015-11-13 18:09:12,916 INFO : Browser exited with error code: 0 18:09:12 INFO - 2015-11-13 18:09:12,918 INFO : Running cycle 11/20 for ts_paint test... 18:09:12 INFO - 2015-11-13 18:09:12,918 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpahoh0b/profile http://localhost:49263/startup_test/tspaint_test.html 18:09:14 INFO - 2015-11-13 18:09:14,897 DEBUG : BROWSER_OUTPUT: __start_report726__end_report 18:09:14 INFO - 2015-11-13 18:09:14,897 DEBUG : BROWSER_OUTPUT: 18:09:14 INFO - 2015-11-13 18:09:14,902 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466954899__endTimestamp 18:09:15 INFO - 2015-11-13 18:09:15,661 INFO : Browser exited with error code: 0 18:09:15 INFO - 2015-11-13 18:09:15,663 INFO : Running cycle 12/20 for ts_paint test... 18:09:15 INFO - 2015-11-13 18:09:15,663 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpahoh0b/profile http://localhost:49263/startup_test/tspaint_test.html 18:09:17 INFO - 2015-11-13 18:09:17,648 DEBUG : BROWSER_OUTPUT: __start_report727__end_report 18:09:17 INFO - 2015-11-13 18:09:17,648 DEBUG : BROWSER_OUTPUT: 18:09:17 INFO - 2015-11-13 18:09:17,650 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466957649__endTimestamp 18:09:18 INFO - 2015-11-13 18:09:18,392 INFO : Browser exited with error code: 0 18:09:18 INFO - 2015-11-13 18:09:18,394 INFO : Running cycle 13/20 for ts_paint test... 18:09:18 INFO - 2015-11-13 18:09:18,394 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpahoh0b/profile http://localhost:49263/startup_test/tspaint_test.html 18:09:20 INFO - 2015-11-13 18:09:20,396 DEBUG : BROWSER_OUTPUT: __start_report741__end_report 18:09:20 INFO - 2015-11-13 18:09:20,396 DEBUG : BROWSER_OUTPUT: 18:09:20 INFO - 2015-11-13 18:09:20,406 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466960402__endTimestamp 18:09:21 INFO - 2015-11-13 18:09:21,167 INFO : Browser exited with error code: 0 18:09:21 INFO - 2015-11-13 18:09:21,169 INFO : Running cycle 14/20 for ts_paint test... 18:09:21 INFO - 2015-11-13 18:09:21,169 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpahoh0b/profile http://localhost:49263/startup_test/tspaint_test.html 18:09:23 INFO - 2015-11-13 18:09:23,127 DEBUG : BROWSER_OUTPUT: __start_report714__end_report 18:09:23 INFO - 2015-11-13 18:09:23,128 DEBUG : BROWSER_OUTPUT: 18:09:23 INFO - 2015-11-13 18:09:23,136 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466963133__endTimestamp 18:09:23 INFO - 2015-11-13 18:09:23,911 INFO : Browser exited with error code: 0 18:09:23 INFO - 2015-11-13 18:09:23,912 INFO : Running cycle 15/20 for ts_paint test... 18:09:23 INFO - 2015-11-13 18:09:23,912 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpahoh0b/profile http://localhost:49263/startup_test/tspaint_test.html 18:09:25 INFO - 2015-11-13 18:09:25,900 DEBUG : BROWSER_OUTPUT: __start_report730__end_report 18:09:25 INFO - 2015-11-13 18:09:25,900 DEBUG : BROWSER_OUTPUT: 18:09:25 INFO - 2015-11-13 18:09:25,903 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466965901__endTimestamp 18:09:26 INFO - 2015-11-13 18:09:26,776 INFO : Browser exited with error code: 0 18:09:26 INFO - 2015-11-13 18:09:26,778 INFO : Running cycle 16/20 for ts_paint test... 18:09:26 INFO - 2015-11-13 18:09:26,778 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpahoh0b/profile http://localhost:49263/startup_test/tspaint_test.html 18:09:28 INFO - 2015-11-13 18:09:28,764 DEBUG : BROWSER_OUTPUT: __start_report728__end_report 18:09:28 INFO - 2015-11-13 18:09:28,764 DEBUG : BROWSER_OUTPUT: 18:09:28 INFO - 2015-11-13 18:09:28,767 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466968766__endTimestamp 18:09:29 INFO - 2015-11-13 18:09:29,479 INFO : Browser exited with error code: 0 18:09:29 INFO - 2015-11-13 18:09:29,480 INFO : Running cycle 17/20 for ts_paint test... 18:09:29 INFO - 2015-11-13 18:09:29,481 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpahoh0b/profile http://localhost:49263/startup_test/tspaint_test.html 18:09:31 INFO - 2015-11-13 18:09:31,462 DEBUG : BROWSER_OUTPUT: __start_report729__end_report 18:09:31 INFO - 2015-11-13 18:09:31,462 DEBUG : BROWSER_OUTPUT: 18:09:31 INFO - 2015-11-13 18:09:31,469 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466971467__endTimestamp 18:09:32 INFO - 2015-11-13 18:09:32,193 INFO : Browser exited with error code: 0 18:09:32 INFO - 2015-11-13 18:09:32,195 INFO : Running cycle 18/20 for ts_paint test... 18:09:32 INFO - 2015-11-13 18:09:32,195 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpahoh0b/profile http://localhost:49263/startup_test/tspaint_test.html 18:09:34 INFO - 2015-11-13 18:09:34,161 DEBUG : BROWSER_OUTPUT: __start_report712__end_report 18:09:34 INFO - 2015-11-13 18:09:34,162 DEBUG : BROWSER_OUTPUT: 18:09:34 INFO - 2015-11-13 18:09:34,170 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466974167__endTimestamp 18:09:34 INFO - 2015-11-13 18:09:34,918 INFO : Browser exited with error code: 0 18:09:34 INFO - 2015-11-13 18:09:34,919 INFO : Running cycle 19/20 for ts_paint test... 18:09:34 INFO - 2015-11-13 18:09:34,919 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpahoh0b/profile http://localhost:49263/startup_test/tspaint_test.html 18:09:36 INFO - 2015-11-13 18:09:36,882 DEBUG : BROWSER_OUTPUT: __start_report709__end_report 18:09:36 INFO - 2015-11-13 18:09:36,882 DEBUG : BROWSER_OUTPUT: 18:09:36 INFO - 2015-11-13 18:09:36,884 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466976883__endTimestamp 18:09:37 INFO - 2015-11-13 18:09:37,621 INFO : Browser exited with error code: 0 18:09:37 INFO - 2015-11-13 18:09:37,622 INFO : Running cycle 20/20 for ts_paint test... 18:09:37 INFO - 2015-11-13 18:09:37,622 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpahoh0b/profile http://localhost:49263/startup_test/tspaint_test.html 18:09:39 INFO - 2015-11-13 18:09:39,579 DEBUG : BROWSER_OUTPUT: __start_report710__end_report 18:09:39 INFO - 2015-11-13 18:09:39,579 DEBUG : BROWSER_OUTPUT: 18:09:39 INFO - 2015-11-13 18:09:39,587 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466979584__endTimestamp 18:09:40 INFO - 2015-11-13 18:09:40,314 INFO : Browser exited with error code: 0 18:09:40 INFO - 2015-11-13 18:09:40,340 INFO : Completed test ts_paint (00:00:58) 18:09:40 INFO - 2015-11-13 18:09:40,340 INFO : Starting test tpaint 18:09:40 INFO - 2015-11-13 18:09:40,340 DEBUG : operating with platform_type : mac_ 18:09:40 INFO - 2015-11-13 18:09:40,340 INFO : Initialising browser for tpaint test... 18:09:40 INFO - 2015-11-13 18:09:40,353 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmptuzEus/profile http://localhost:49263/getInfo.html 18:09:43 INFO - 2015-11-13 18:09:43,169 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 18:09:43 INFO - 2015-11-13 18:09:43,169 DEBUG : BROWSER_OUTPUT: colorDepth:24 18:09:43 INFO - 2015-11-13 18:09:43,169 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/689 18:09:43 INFO - 2015-11-13 18:09:43,169 DEBUG : BROWSER_OUTPUT: __metrics 18:09:43 INFO - 2015-11-13 18:09:43,826 INFO : Browser initialized. 18:09:43 INFO - 2015-11-13 18:09:43,827 INFO : Running cycle 1/1 for tpaint test... 18:09:43 INFO - 2015-11-13 18:09:43,827 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmptuzEus/profile file:///builds/slave/test/build/tests/talos/talos/startup_test/tpaint.html?auto=1 18:10:14 INFO - 2015-11-13 18:10:14,305 DEBUG : BROWSER_OUTPUT: __start_report372.3349999999991|372.52000000000044|372.64999999999964|374.5799999999999|374.75000000000045|382.380000000001|383.0849999999991|384.46500000000015|399.01500000000124|399.64500000000044|401.72500000000036|408.84500000000116|422.85000000000036|424.4900000000001|425.52000000000044|427.6950000000006|427.80499999999665|431.0099999999984|437.03499999999985|529.0699999999997__end_report__startTimestamp1447467014305__endTimestamp 18:10:14 INFO - 2015-11-13 18:10:14,306 DEBUG : BROWSER_OUTPUT: openingTimes=372.52000000000044,372.64999999999964,374.5799999999999,374.75000000000045,382.380000000001,383.0849999999991,384.46500000000015,399.01500000000124,399.64500000000044,401.72500000000036,408.84500000000116,422.85000000000036,424.4900000000001,425.52000000000044,427.6950000000006,427.80499999999665,431.0099999999984,437.03499999999985,529.0699999999997 18:10:14 INFO - 2015-11-13 18:10:14,308 DEBUG : BROWSER_OUTPUT: avgOpenTime:407.57 18:10:14 INFO - 2015-11-13 18:10:14,308 DEBUG : BROWSER_OUTPUT: minOpenTime:372.33 18:10:14 INFO - 2015-11-13 18:10:14,308 DEBUG : BROWSER_OUTPUT: maxOpenTime:529.07 18:10:14 INFO - 2015-11-13 18:10:14,308 DEBUG : BROWSER_OUTPUT: medOpenTime:400.6850000000004 18:10:14 INFO - 2015-11-13 18:10:14,309 DEBUG : BROWSER_OUTPUT: __xulWinOpenTime:400.6850000000004 18:10:15 INFO - 2015-11-13 18:10:15,659 INFO : Browser exited with error code: 0 18:10:15 INFO - 2015-11-13 18:10:15,677 INFO : Completed test tpaint (00:00:35) 18:10:15 INFO - 2015-11-13 18:10:15,677 INFO : Starting test sessionrestore 18:10:15 INFO - 2015-11-13 18:10:15,677 DEBUG : operating with platform_type : mac_ 18:10:15 INFO - 2015-11-13 18:10:15,677 INFO : Initialising browser for sessionrestore test... 18:10:15 INFO - 2015-11-13 18:10:15,817 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile http://localhost:49263/getInfo.html 18:10:21 INFO - 2015-11-13 18:10:21,648 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 18:10:21 INFO - 2015-11-13 18:10:21,648 DEBUG : BROWSER_OUTPUT: colorDepth:24 18:10:21 INFO - 2015-11-13 18:10:21,649 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1200/743 18:10:21 INFO - 2015-11-13 18:10:21,649 DEBUG : BROWSER_OUTPUT: __metrics 18:10:21 ERROR - 2015-11-13 18:10:21,970 DEBUG : BROWSER_OUTPUT: JavaScript error: chrome://browser/content/browser.js, line 17448: TypeError: browser.permitUnload is not a function 18:10:22 ERROR - 2015-11-13 18:10:22,217 DEBUG : BROWSER_OUTPUT: JavaScript error: chrome://browser/content/browser.js, line 17448: TypeError: browser.permitUnload is not a function 18:10:22 INFO - 2015-11-13 18:10:22,903 INFO : Browser initialized. 18:10:22 INFO - 2015-11-13 18:10:22,903 INFO : Running cycle 1/10 for sessionrestore test... 18:10:22 INFO - 2015-11-13 18:10:22,903 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile/sessionstore.js 18:10:22 INFO - 2015-11-13 18:10:22,905 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile/sessionCheckpoints.json 18:10:22 INFO - 2015-11-13 18:10:22,905 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile http://localhost:49263/startup_test/sessionrestore/index.html 18:10:28 INFO - 2015-11-13 18:10:28,297 DEBUG : BROWSER_OUTPUT: __start_report1658__end_report 18:10:28 INFO - 2015-11-13 18:10:28,297 DEBUG : BROWSER_OUTPUT: 18:10:28 INFO - 2015-11-13 18:10:28,298 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467028297__endTimestamp 18:10:28 INFO - 2015-11-13 18:10:28,298 DEBUG : BROWSER_OUTPUT: 18:10:29 INFO - 2015-11-13 18:10:29,462 INFO : Browser exited with error code: 0 18:10:29 INFO - 2015-11-13 18:10:29,464 INFO : Running cycle 2/10 for sessionrestore test... 18:10:29 INFO - 2015-11-13 18:10:29,464 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile/sessionstore.js 18:10:29 INFO - 2015-11-13 18:10:29,485 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile/sessionCheckpoints.json 18:10:29 INFO - 2015-11-13 18:10:29,486 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile http://localhost:49263/startup_test/sessionrestore/index.html 18:10:34 INFO - 2015-11-13 18:10:34,573 DEBUG : BROWSER_OUTPUT: __start_report1331__end_report 18:10:34 INFO - 2015-11-13 18:10:34,573 DEBUG : BROWSER_OUTPUT: 18:10:34 INFO - 2015-11-13 18:10:34,573 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467034571__endTimestamp 18:10:34 INFO - 2015-11-13 18:10:34,573 DEBUG : BROWSER_OUTPUT: 18:10:35 INFO - 2015-11-13 18:10:35,590 INFO : Browser exited with error code: 0 18:10:35 INFO - 2015-11-13 18:10:35,591 INFO : Running cycle 3/10 for sessionrestore test... 18:10:35 INFO - 2015-11-13 18:10:35,591 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile/sessionstore.js 18:10:35 INFO - 2015-11-13 18:10:35,614 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile/sessionCheckpoints.json 18:10:35 INFO - 2015-11-13 18:10:35,614 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile http://localhost:49263/startup_test/sessionrestore/index.html 18:10:40 INFO - 2015-11-13 18:10:40,707 DEBUG : BROWSER_OUTPUT: __start_report1334__end_report 18:10:40 INFO - 2015-11-13 18:10:40,707 DEBUG : BROWSER_OUTPUT: 18:10:40 INFO - 2015-11-13 18:10:40,707 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467040704__endTimestamp 18:10:40 INFO - 2015-11-13 18:10:40,708 DEBUG : BROWSER_OUTPUT: 18:10:41 INFO - 2015-11-13 18:10:41,760 INFO : Browser exited with error code: 0 18:10:41 INFO - 2015-11-13 18:10:41,761 INFO : Running cycle 4/10 for sessionrestore test... 18:10:41 INFO - 2015-11-13 18:10:41,762 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile/sessionstore.js 18:10:41 INFO - 2015-11-13 18:10:41,785 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile/sessionCheckpoints.json 18:10:41 INFO - 2015-11-13 18:10:41,785 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile http://localhost:49263/startup_test/sessionrestore/index.html 18:10:46 INFO - 2015-11-13 18:10:46,875 DEBUG : BROWSER_OUTPUT: __start_report1333__end_report 18:10:46 INFO - 2015-11-13 18:10:46,875 DEBUG : BROWSER_OUTPUT: 18:10:46 INFO - 2015-11-13 18:10:46,876 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467046870__endTimestamp 18:10:46 INFO - 2015-11-13 18:10:46,876 DEBUG : BROWSER_OUTPUT: 18:10:47 INFO - 2015-11-13 18:10:47,977 INFO : Browser exited with error code: 0 18:10:47 INFO - 2015-11-13 18:10:47,978 INFO : Running cycle 5/10 for sessionrestore test... 18:10:47 INFO - 2015-11-13 18:10:47,979 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile/sessionstore.js 18:10:48 INFO - 2015-11-13 18:10:48,004 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile/sessionCheckpoints.json 18:10:48 INFO - 2015-11-13 18:10:48,004 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile http://localhost:49263/startup_test/sessionrestore/index.html 18:10:53 INFO - 2015-11-13 18:10:53,098 DEBUG : BROWSER_OUTPUT: __start_report1332__end_report 18:10:53 INFO - 2015-11-13 18:10:53,098 DEBUG : BROWSER_OUTPUT: 18:10:53 INFO - 2015-11-13 18:10:53,098 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467053096__endTimestamp 18:10:53 INFO - 2015-11-13 18:10:53,098 DEBUG : BROWSER_OUTPUT: 18:10:54 INFO - 2015-11-13 18:10:54,377 INFO : Browser exited with error code: 0 18:10:54 INFO - 2015-11-13 18:10:54,378 INFO : Running cycle 6/10 for sessionrestore test... 18:10:54 INFO - 2015-11-13 18:10:54,379 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile/sessionstore.js 18:10:54 INFO - 2015-11-13 18:10:54,384 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile/sessionCheckpoints.json 18:10:54 INFO - 2015-11-13 18:10:54,385 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile http://localhost:49263/startup_test/sessionrestore/index.html 18:10:59 INFO - 2015-11-13 18:10:59,509 DEBUG : BROWSER_OUTPUT: __start_report1341__end_report 18:10:59 INFO - 2015-11-13 18:10:59,509 DEBUG : BROWSER_OUTPUT: 18:10:59 INFO - 2015-11-13 18:10:59,509 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467059507__endTimestamp 18:10:59 INFO - 2015-11-13 18:10:59,510 DEBUG : BROWSER_OUTPUT: 18:11:00 INFO - 2015-11-13 18:11:00,675 INFO : Browser exited with error code: 0 18:11:00 INFO - 2015-11-13 18:11:00,676 INFO : Running cycle 7/10 for sessionrestore test... 18:11:00 INFO - 2015-11-13 18:11:00,676 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile/sessionstore.js 18:11:00 INFO - 2015-11-13 18:11:00,682 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile/sessionCheckpoints.json 18:11:00 INFO - 2015-11-13 18:11:00,682 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile http://localhost:49263/startup_test/sessionrestore/index.html 18:11:05 INFO - 2015-11-13 18:11:05,781 DEBUG : BROWSER_OUTPUT: __start_report1335__end_report 18:11:05 INFO - 2015-11-13 18:11:05,781 DEBUG : BROWSER_OUTPUT: 18:11:05 INFO - 2015-11-13 18:11:05,782 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467065778__endTimestamp 18:11:05 INFO - 2015-11-13 18:11:05,782 DEBUG : BROWSER_OUTPUT: 18:11:06 INFO - 2015-11-13 18:11:06,978 INFO : Browser exited with error code: 0 18:11:06 INFO - 2015-11-13 18:11:06,980 INFO : Running cycle 8/10 for sessionrestore test... 18:11:06 INFO - 2015-11-13 18:11:06,980 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile/sessionstore.js 18:11:06 INFO - 2015-11-13 18:11:06,986 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile/sessionCheckpoints.json 18:11:06 INFO - 2015-11-13 18:11:06,986 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile http://localhost:49263/startup_test/sessionrestore/index.html 18:11:12 INFO - 2015-11-13 18:11:12,087 DEBUG : BROWSER_OUTPUT: __start_report1348__end_report 18:11:12 INFO - 2015-11-13 18:11:12,087 DEBUG : BROWSER_OUTPUT: 18:11:12 INFO - 2015-11-13 18:11:12,087 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467072084__endTimestamp 18:11:12 INFO - 2015-11-13 18:11:12,088 DEBUG : BROWSER_OUTPUT: 18:11:13 INFO - 2015-11-13 18:11:13,278 INFO : Browser exited with error code: 0 18:11:13 INFO - 2015-11-13 18:11:13,280 INFO : Running cycle 9/10 for sessionrestore test... 18:11:13 INFO - 2015-11-13 18:11:13,280 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile/sessionstore.js 18:11:13 INFO - 2015-11-13 18:11:13,286 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile/sessionCheckpoints.json 18:11:13 INFO - 2015-11-13 18:11:13,286 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile http://localhost:49263/startup_test/sessionrestore/index.html 18:11:18 INFO - 2015-11-13 18:11:18,391 DEBUG : BROWSER_OUTPUT: __start_report1351__end_report 18:11:18 INFO - 2015-11-13 18:11:18,392 DEBUG : BROWSER_OUTPUT: 18:11:18 INFO - 2015-11-13 18:11:18,392 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467078391__endTimestamp 18:11:18 INFO - 2015-11-13 18:11:18,392 DEBUG : BROWSER_OUTPUT: 18:11:19 INFO - 2015-11-13 18:11:19,579 INFO : Browser exited with error code: 0 18:11:19 INFO - 2015-11-13 18:11:19,581 INFO : Running cycle 10/10 for sessionrestore test... 18:11:19 INFO - 2015-11-13 18:11:19,581 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile/sessionstore.js 18:11:19 INFO - 2015-11-13 18:11:19,587 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile/sessionCheckpoints.json 18:11:19 INFO - 2015-11-13 18:11:19,587 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmplWfagy/profile http://localhost:49263/startup_test/sessionrestore/index.html 18:11:24 INFO - 2015-11-13 18:11:24,691 DEBUG : BROWSER_OUTPUT: __start_report1347__end_report 18:11:24 INFO - 2015-11-13 18:11:24,691 DEBUG : BROWSER_OUTPUT: 18:11:24 INFO - 2015-11-13 18:11:24,691 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467084690__endTimestamp 18:11:24 INFO - 2015-11-13 18:11:24,691 DEBUG : BROWSER_OUTPUT: 18:11:25 INFO - 2015-11-13 18:11:25,978 INFO : Browser exited with error code: 0 18:11:26 INFO - 2015-11-13 18:11:26,001 INFO : Completed test sessionrestore (00:01:10) 18:11:26 INFO - 2015-11-13 18:11:26,001 INFO : Starting test sessionrestore_no_auto_restore 18:11:26 INFO - 2015-11-13 18:11:26,001 DEBUG : operating with platform_type : mac_ 18:11:26 INFO - 2015-11-13 18:11:26,002 INFO : Initialising browser for sessionrestore_no_auto_restore test... 18:11:26 INFO - 2015-11-13 18:11:26,022 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile http://localhost:49263/getInfo.html 18:11:28 INFO - 2015-11-13 18:11:28,866 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 18:11:28 INFO - 2015-11-13 18:11:28,866 DEBUG : BROWSER_OUTPUT: colorDepth:24 18:11:28 INFO - 2015-11-13 18:11:28,866 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1200/743 18:11:28 INFO - 2015-11-13 18:11:28,866 DEBUG : BROWSER_OUTPUT: __metrics 18:11:29 INFO - 2015-11-13 18:11:29,494 INFO : Browser initialized. 18:11:29 INFO - 2015-11-13 18:11:29,494 INFO : Running cycle 1/10 for sessionrestore_no_auto_restore test... 18:11:29 INFO - 2015-11-13 18:11:29,494 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile/sessionstore.js 18:11:29 INFO - 2015-11-13 18:11:29,514 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile/sessionCheckpoints.json 18:11:29 INFO - 2015-11-13 18:11:29,515 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile http://localhost:49263/startup_test/sessionrestore/index.html 18:11:31 INFO - 2015-11-13 18:11:31,977 DEBUG : BROWSER_OUTPUT: __start_report1251__end_report 18:11:31 INFO - 2015-11-13 18:11:31,977 DEBUG : BROWSER_OUTPUT: 18:11:31 INFO - 2015-11-13 18:11:31,977 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467091972__endTimestamp 18:11:31 INFO - 2015-11-13 18:11:31,978 DEBUG : BROWSER_OUTPUT: 18:11:32 INFO - 2015-11-13 18:11:32,645 INFO : Browser exited with error code: 0 18:11:32 INFO - 2015-11-13 18:11:32,647 INFO : Running cycle 2/10 for sessionrestore_no_auto_restore test... 18:11:32 INFO - 2015-11-13 18:11:32,647 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile/sessionstore.js 18:11:32 INFO - 2015-11-13 18:11:32,649 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile/sessionCheckpoints.json 18:11:32 INFO - 2015-11-13 18:11:32,650 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile http://localhost:49263/startup_test/sessionrestore/index.html 18:11:34 INFO - 2015-11-13 18:11:34,663 DEBUG : BROWSER_OUTPUT: __start_report963__end_report 18:11:34 INFO - 2015-11-13 18:11:34,663 DEBUG : BROWSER_OUTPUT: 18:11:34 INFO - 2015-11-13 18:11:34,663 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467094659__endTimestamp 18:11:34 INFO - 2015-11-13 18:11:34,663 DEBUG : BROWSER_OUTPUT: 18:11:35 INFO - 2015-11-13 18:11:35,273 INFO : Browser exited with error code: 0 18:11:35 INFO - 2015-11-13 18:11:35,275 INFO : Running cycle 3/10 for sessionrestore_no_auto_restore test... 18:11:35 INFO - 2015-11-13 18:11:35,275 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile/sessionstore.js 18:11:35 INFO - 2015-11-13 18:11:35,280 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile/sessionCheckpoints.json 18:11:35 INFO - 2015-11-13 18:11:35,281 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile http://localhost:49263/startup_test/sessionrestore/index.html 18:11:37 INFO - 2015-11-13 18:11:37,278 DEBUG : BROWSER_OUTPUT: __start_report951__end_report 18:11:37 INFO - 2015-11-13 18:11:37,279 DEBUG : BROWSER_OUTPUT: 18:11:37 INFO - 2015-11-13 18:11:37,279 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467097274__endTimestamp 18:11:37 INFO - 2015-11-13 18:11:37,279 DEBUG : BROWSER_OUTPUT: 18:11:37 INFO - 2015-11-13 18:11:37,929 INFO : Browser exited with error code: 0 18:11:37 INFO - 2015-11-13 18:11:37,931 INFO : Running cycle 4/10 for sessionrestore_no_auto_restore test... 18:11:37 INFO - 2015-11-13 18:11:37,931 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile/sessionstore.js 18:11:37 INFO - 2015-11-13 18:11:37,937 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile/sessionCheckpoints.json 18:11:37 INFO - 2015-11-13 18:11:37,937 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile http://localhost:49263/startup_test/sessionrestore/index.html 18:11:39 INFO - 2015-11-13 18:11:39,939 DEBUG : BROWSER_OUTPUT: __start_report963__end_report 18:11:39 INFO - 2015-11-13 18:11:39,940 DEBUG : BROWSER_OUTPUT: 18:11:39 INFO - 2015-11-13 18:11:39,940 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467099937__endTimestamp 18:11:39 INFO - 2015-11-13 18:11:39,940 DEBUG : BROWSER_OUTPUT: 18:11:40 INFO - 2015-11-13 18:11:40,606 INFO : Browser exited with error code: 0 18:11:40 INFO - 2015-11-13 18:11:40,608 INFO : Running cycle 5/10 for sessionrestore_no_auto_restore test... 18:11:40 INFO - 2015-11-13 18:11:40,608 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile/sessionstore.js 18:11:40 INFO - 2015-11-13 18:11:40,617 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile/sessionCheckpoints.json 18:11:40 INFO - 2015-11-13 18:11:40,617 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile http://localhost:49263/startup_test/sessionrestore/index.html 18:11:42 INFO - 2015-11-13 18:11:42,622 DEBUG : BROWSER_OUTPUT: __start_report956__end_report 18:11:42 INFO - 2015-11-13 18:11:42,623 DEBUG : BROWSER_OUTPUT: 18:11:42 INFO - 2015-11-13 18:11:42,623 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467102620__endTimestamp 18:11:42 INFO - 2015-11-13 18:11:42,623 DEBUG : BROWSER_OUTPUT: 18:11:43 INFO - 2015-11-13 18:11:43,346 INFO : Browser exited with error code: 0 18:11:43 INFO - 2015-11-13 18:11:43,347 INFO : Running cycle 6/10 for sessionrestore_no_auto_restore test... 18:11:43 INFO - 2015-11-13 18:11:43,348 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile/sessionstore.js 18:11:43 INFO - 2015-11-13 18:11:43,353 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile/sessionCheckpoints.json 18:11:43 INFO - 2015-11-13 18:11:43,354 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile http://localhost:49263/startup_test/sessionrestore/index.html 18:11:45 INFO - 2015-11-13 18:11:45,361 DEBUG : BROWSER_OUTPUT: __start_report958__end_report 18:11:45 INFO - 2015-11-13 18:11:45,362 DEBUG : BROWSER_OUTPUT: 18:11:45 INFO - 2015-11-13 18:11:45,362 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467105361__endTimestamp 18:11:45 INFO - 2015-11-13 18:11:45,362 DEBUG : BROWSER_OUTPUT: 18:11:46 INFO - 2015-11-13 18:11:46,096 INFO : Browser exited with error code: 0 18:11:46 INFO - 2015-11-13 18:11:46,097 INFO : Running cycle 7/10 for sessionrestore_no_auto_restore test... 18:11:46 INFO - 2015-11-13 18:11:46,097 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile/sessionstore.js 18:11:46 INFO - 2015-11-13 18:11:46,104 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile/sessionCheckpoints.json 18:11:46 INFO - 2015-11-13 18:11:46,104 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile http://localhost:49263/startup_test/sessionrestore/index.html 18:11:48 INFO - 2015-11-13 18:11:48,103 DEBUG : BROWSER_OUTPUT: __start_report958__end_report 18:11:48 INFO - 2015-11-13 18:11:48,104 DEBUG : BROWSER_OUTPUT: 18:11:48 INFO - 2015-11-13 18:11:48,104 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467108103__endTimestamp 18:11:48 INFO - 2015-11-13 18:11:48,104 DEBUG : BROWSER_OUTPUT: 18:11:48 INFO - 2015-11-13 18:11:48,868 INFO : Browser exited with error code: 0 18:11:48 INFO - 2015-11-13 18:11:48,870 INFO : Running cycle 8/10 for sessionrestore_no_auto_restore test... 18:11:48 INFO - 2015-11-13 18:11:48,870 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile/sessionstore.js 18:11:48 INFO - 2015-11-13 18:11:48,875 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile/sessionCheckpoints.json 18:11:48 INFO - 2015-11-13 18:11:48,875 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile http://localhost:49263/startup_test/sessionrestore/index.html 18:11:50 INFO - 2015-11-13 18:11:50,881 DEBUG : BROWSER_OUTPUT: __start_report954__end_report 18:11:50 INFO - 2015-11-13 18:11:50,881 DEBUG : BROWSER_OUTPUT: 18:11:50 INFO - 2015-11-13 18:11:50,881 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467110877__endTimestamp 18:11:50 INFO - 2015-11-13 18:11:50,881 DEBUG : BROWSER_OUTPUT: 18:11:51 INFO - 2015-11-13 18:11:51,626 INFO : Browser exited with error code: 0 18:11:51 INFO - 2015-11-13 18:11:51,628 INFO : Running cycle 9/10 for sessionrestore_no_auto_restore test... 18:11:51 INFO - 2015-11-13 18:11:51,628 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile/sessionstore.js 18:11:51 INFO - 2015-11-13 18:11:51,633 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile/sessionCheckpoints.json 18:11:51 INFO - 2015-11-13 18:11:51,634 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile http://localhost:49263/startup_test/sessionrestore/index.html 18:11:53 INFO - 2015-11-13 18:11:53,647 DEBUG : BROWSER_OUTPUT: __start_report960__end_report 18:11:53 INFO - 2015-11-13 18:11:53,648 DEBUG : BROWSER_OUTPUT: 18:11:53 INFO - 2015-11-13 18:11:53,648 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467113639__endTimestamp 18:11:53 INFO - 2015-11-13 18:11:53,648 DEBUG : BROWSER_OUTPUT: 18:11:54 INFO - 2015-11-13 18:11:54,352 INFO : Browser exited with error code: 0 18:11:54 INFO - 2015-11-13 18:11:54,353 INFO : Running cycle 10/10 for sessionrestore_no_auto_restore test... 18:11:54 INFO - 2015-11-13 18:11:54,353 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile/sessionstore.js 18:11:54 INFO - 2015-11-13 18:11:54,378 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile/sessionCheckpoints.json 18:11:54 INFO - 2015-11-13 18:11:54,379 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp2anT7D/profile http://localhost:49263/startup_test/sessionrestore/index.html 18:11:56 INFO - 2015-11-13 18:11:56,409 DEBUG : BROWSER_OUTPUT: __start_report968__end_report 18:11:56 INFO - 2015-11-13 18:11:56,409 DEBUG : BROWSER_OUTPUT: 18:11:56 INFO - 2015-11-13 18:11:56,409 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467116407__endTimestamp 18:11:56 INFO - 2015-11-13 18:11:56,410 DEBUG : BROWSER_OUTPUT: 18:11:57 INFO - 2015-11-13 18:11:57,107 INFO : Browser exited with error code: 0 18:11:57 INFO - 2015-11-13 18:11:57,129 INFO : Completed test sessionrestore_no_auto_restore (00:00:31) 18:11:57 INFO - 2015-11-13 18:11:57,307 INFO : Completed test suite (00:04:49) 18:11:57 INFO - 2015-11-13 18:11:57,308 DEBUG : Working with test: a11yr 18:11:57 INFO - 2015-11-13 18:11:57,308 DEBUG : Generating results file: a11yr 18:11:57 INFO - 2015-11-13 18:11:57,308 DEBUG : Working with test: ts_paint 18:11:57 INFO - 2015-11-13 18:11:57,308 DEBUG : Generating results file: ts_paint 18:11:57 INFO - 2015-11-13 18:11:57,309 DEBUG : Working with test: tpaint 18:11:57 INFO - 2015-11-13 18:11:57,309 DEBUG : Generating results file: tpaint 18:11:57 INFO - 2015-11-13 18:11:57,309 DEBUG : Working with test: sessionrestore 18:11:57 INFO - 2015-11-13 18:11:57,309 DEBUG : Generating results file: sessionrestore 18:11:57 INFO - 2015-11-13 18:11:57,309 DEBUG : Working with test: sessionrestore_no_auto_restore 18:11:57 INFO - 2015-11-13 18:11:57,309 DEBUG : Generating results file: sessionrestore_no_auto_restore 18:11:57 INFO - 2015-11-13 18:11:57,309 INFO : Posting result 0 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 18:11:57 INFO - 2015-11-13 18:11:57,394 DEBUG : process_Request line: a11yr_paint graph.html#tests=[[223,64,57]] 18:11:57 INFO - 2015-11-13 18:11:57,394 DEBUG : process_Request line: a11yr_paint 538.98 graph.html#tests=[[223,64,57]] 18:11:57 INFO - 2015-11-13 18:11:57,395 INFO : Posting result 1 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 18:11:57 INFO - 2015-11-13 18:11:57,460 DEBUG : process_Request line: ts_paint graph.html#tests=[[83,64,57]] 18:11:57 INFO - 2015-11-13 18:11:57,460 DEBUG : process_Request line: ts_paint 722.01 graph.html#tests=[[83,64,57]] 18:11:57 INFO - 2015-11-13 18:11:57,460 INFO : Posting result 2 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 18:11:57 INFO - 2015-11-13 18:11:57,506 DEBUG : process_Request line: tpaint graph.html#tests=[[82,64,57]] 18:11:57 INFO - 2015-11-13 18:11:57,506 DEBUG : process_Request line: tpaint 422.85 graph.html#tests=[[82,64,57]] 18:11:57 INFO - 2015-11-13 18:11:57,506 INFO : Posting result 3 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 18:11:57 INFO - 2015-11-13 18:11:57,551 DEBUG : process_Request line: sessionrestore graph.html#tests=[[313,64,57]] 18:11:57 INFO - 2015-11-13 18:11:57,551 DEBUG : process_Request line: sessionrestore 1368.01 graph.html#tests=[[313,64,57]] 18:11:57 INFO - 2015-11-13 18:11:57,551 INFO : Posting result 4 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 18:11:57 INFO - 2015-11-13 18:11:57,599 DEBUG : process_Request line: sessionrestore_no_auto_restore graph.html#tests=[[315,64,57]] 18:11:57 INFO - 2015-11-13 18:11:57,599 DEBUG : process_Request line: sessionrestore_no_auto_restore 984.82 graph.html#tests=[[315,64,57]] 18:11:57 INFO - 2015-11-13 18:11:57,600 INFO : TALOSDATA: [{"talos_counters": {}, "results": {"dhtml.html": [936.0, 973.0, 954.0, 1017.0, 1157.0, 993.0, 1013.0, 1000.0, 1013.0, 1005.0, 1006.0, 984.0, 1004.0, 1007.0, 1001.0, 1003.0, 1146.0, 988.0, 997.0, 996.0, 1000.0, 1001.0, 1002.0, 999.0, 997.0], "tablemutation.html": [301.0, 289.0, 289.0, 300.0, 303.0, 301.0, 290.0, 288.0, 286.0, 289.0, 292.0, 287.0, 299.0, 292.0, 291.0, 290.0, 287.0, 290.0, 290.0, 290.0, 290.0, 292.0, 291.0, 290.0, 293.0]}, "summary": {"lowerIsBetter": true, "suite": 538.9833330761238, "subtests": {"dhtml.html": {"lowerIsBetter": true, "filtered": 1001.0, "unit": "ms", "value": 1001.0}, "tablemutation.html": {"lowerIsBetter": true, "filtered": 290.0, "unit": "ms", "value": 290.0}}}, "test_machine": {"platform": "x86_64", "osversion": "OS X 10.10.2.e", "os": "mac", "name": "t-yosemite-r5-0016.e"}, "testrun": {"date": 1447466828, "suite": "a11yr", "options": {"responsiveness": false, "tpmozafterpaint": true, "tpchrome": true, "tppagecycles": 25, "tpcycles": 1, "tprender": false, "shutdown": false, "cycles": 1, "rss": false}}, "test_build": {"name": "Firefox", "version": "45.0a1", "id": "20151113165331", "branch": "Fx-Team", "revision": "031994a3b4e47b1d9ad1c0e4be0b98bdc4e7e242"}}, {"talos_counters": {}, "results": {"ts_paint": [699.0, 746.0, 726.0, 727.0, 724.0, 710.0, 725.0, 726.0, 724.0, 709.0, 726.0, 727.0, 741.0, 714.0, 730.0, 728.0, 729.0, 712.0, 709.0, 710.0]}, "summary": {"suite": 726.0, "subtests": {"ts_paint": {"filtered": 726.0, "value": 726.0}}}, "test_machine": {"platform": "x86_64", "osversion": "OS X 10.10.2.e", "os": "mac", "name": "t-yosemite-r5-0016.e"}, "testrun": {"date": 1447466828, "suite": "ts_paint", "options": {"responsiveness": false, "cycles": 20, "tpmozafterpaint": true, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "45.0a1", "id": "20151113165331", "branch": "Fx-Team", "revision": "031994a3b4e47b1d9ad1c0e4be0b98bdc4e7e242"}}, {"talos_counters": {}, "results": {"tpaint": [372.3349999999991, 372.52000000000044, 372.64999999999964, 374.5799999999999, 374.75000000000045, 382.380000000001, 383.0849999999991, 384.46500000000015, 399.01500000000124, 399.64500000000044, 401.72500000000036, 408.84500000000116, 422.85000000000036, 424.4900000000001, 425.52000000000044, 427.6950000000006, 427.80499999999665, 431.0099999999984, 437.03499999999985, 529.0699999999997]}, "summary": {"suite": 422.85000000000036, "subtests": {"tpaint": {"filtered": 422.85000000000036, "value": 422.85000000000036}}}, "test_machine": {"platform": "x86_64", "osversion": "OS X 10.10.2.e", "os": "mac", "name": "t-yosemite-r5-0016.e"}, "testrun": {"date": 1447466828, "suite": "tpaint", "options": {"responsiveness": false, "cycles": 1, "tpmozafterpaint": true, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "45.0a1", "id": "20151113165331", "branch": "Fx-Team", "revision": "031994a3b4e47b1d9ad1c0e4be0b98bdc4e7e242"}}, {"talos_counters": {}, "results": {"sessionrestore": [1658.0, 1331.0, 1334.0, 1333.0, 1332.0, 1341.0, 1335.0, 1348.0, 1351.0, 1347.0]}, "summary": {"suite": 1335.0, "subtests": {"sessionrestore": {"filtered": 1335.0, "value": 1335.0}}}, "test_machine": {"platform": "x86_64", "osversion": "OS X 10.10.2.e", "os": "mac", "name": "t-yosemite-r5-0016.e"}, "testrun": {"date": 1447466828, "suite": "sessionrestore", "options": {"responsiveness": false, "cycles": 10, "tpmozafterpaint": false, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "45.0a1", "id": "20151113165331", "branch": "Fx-Team", "revision": "031994a3b4e47b1d9ad1c0e4be0b98bdc4e7e242"}}, {"talos_counters": {}, "results": {"sessionrestore_no_auto_restore": [1251.0, 963.0, 951.0, 963.0, 956.0, 958.0, 958.0, 954.0, 960.0, 968.0]}, "summary": {"suite": 958.0, "subtests": {"sessionrestore_no_auto_restore": {"filtered": 958.0, "value": 958.0}}}, "test_machine": {"platform": "x86_64", "osversion": "OS X 10.10.2.e", "os": "mac", "name": "t-yosemite-r5-0016.e"}, "testrun": {"date": 1447466828, "suite": "sessionrestore_no_auto_restore", "options": {"responsiveness": false, "cycles": 10, "tpmozafterpaint": false, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "45.0a1", "id": "20151113165331", "branch": "Fx-Team", "revision": "031994a3b4e47b1d9ad1c0e4be0b98bdc4e7e242"}}] 18:11:57 INFO - RETURN: a11yr_paint: 538.98 18:11:57 INFO - RETURN: ts_paint: 722.01 18:11:57 INFO - RETURN: tpaint: 422.85 18:11:57 INFO - RETURN: sessionrestore: 1368.01 18:11:57 INFO - RETURN: sessionrestore_no_auto_restore: 984.82 18:11:57 INFO - TinderboxPrint: TalosResult: {"graphserver": {"sessionrestore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[313,64,57]]", "result": "1368.01"}, "a11yr_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[223,64,57]]", "result": "538.98"}, "tpaint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[82,64,57]]", "result": "422.85"}, "ts_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[83,64,57]]", "result": "722.01"}, "sessionrestore_no_auto_restore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[315,64,57]]", "result": "984.82"}}} 18:11:57 INFO - Return code: 0 18:11:57 ERROR - # TBPL SUCCESS # 18:11:57 INFO - Running pre test command check_screen_resolution with 'bash -c screenresolution get && screenresolution list && system_profiler SPDisplaysDataType' 18:11:57 INFO - Running command: ['bash', '-c', 'screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'] in /builds/slave/test/build 18:11:57 INFO - Copy/paste: bash -c "screenresolution get && screenresolution list && system_profiler SPDisplaysDataType" 18:11:57 INFO - 2015-11-13 18:11:57.686 screenresolution[1747:14924] starting screenresolution argv=screenresolution get 18:11:57 INFO - 2015-11-13 18:11:57.689 screenresolution[1747:14924] Display 0: 1600x1200x32@60 18:11:57 INFO - 2015-11-13 18:11:57.695 screenresolution[1748:14926] starting screenresolution argv=screenresolution list 18:11:57 INFO - Available Modes on Display 0 18:11:57 INFO - 1600x1200x32@60 1152x870x32@75 1280x1024x32@75 18:11:57 INFO - 1024x768x32@75 1024x768x32@70 1024x768x32@60 18:11:57 INFO - 800x600x32@75 800x600x32@60 640x480x32@75 18:11:57 INFO - 640x480x32@60 1280x1024x32@60 1280x960x32@60 18:11:57 INFO - 1280x960x32@75 1344x1008x32@60 Graphics/Displays: 18:11:57 INFO - Intel HD Graphics 3000: 18:11:57 INFO - Chipset Model: Intel HD Graphics 3000 18:11:57 INFO - Type: GPU 18:11:57 INFO - Bus: Built-In 18:11:57 INFO - VRAM (Total): 512 MB 18:11:57 INFO - VRAM (Dynamic, Max): 10 18:11:57 INFO - Vendor: Intel (0x8086) 18:11:57 INFO - Device ID: 0x0116 18:11:57 INFO - Revision ID: 0x0009 18:11:57 INFO - Displays: 18:11:57 INFO - Display: 18:11:57 INFO - Resolution: 1600 x 1200 @ 60 Hz 18:11:57 INFO - Pixel Depth: 32-Bit Color (ARGB8888) 18:11:57 INFO - Display Serial Number: 1600x1200 60 18:11:57 INFO - Main Display: Yes 18:11:57 INFO - Mirror: Off 18:11:57 INFO - Online: Yes 18:11:57 INFO - Rotation: Supported 18:11:57 INFO - Return code: 0 18:11:57 INFO - Running post-action listener: _resource_record_post_action 18:11:57 INFO - Running post-run listener: _resource_record_post_run 18:11:58 INFO - Total resource usage - Wall time: 328s; CPU: 32.0%; Read bytes: 41821184; Write bytes: 612292608; Read time: 5187; Write time: 21979 18:11:58 INFO - install - Wall time: 38s; CPU: 30.0%; Read bytes: 241664; Write bytes: 344549376; Read time: 403; Write time: 6103 18:11:58 INFO - run-tests - Wall time: 290s; CPU: 32.0%; Read bytes: 38560768; Write bytes: 266412032; Read time: 4441; Write time: 15857 18:11:58 INFO - Running post-run listener: _upload_blobber_files 18:11:58 INFO - Blob upload gear active. 18:11:58 INFO - There are no files to upload in the directory. Skipping the blob upload mechanism ... 18:11:58 INFO - Copying logs to upload dir... 18:11:58 INFO - mkdir: /builds/slave/test/build/upload/logs program finished with exit code 0 elapsedTime=387.820851 ========= master_lag: 0.04 ========= ========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 6 mins, 27 secs) (at 2015-11-13 18:11:59.018491) ========= ========= Started set props: build_url (results: 0, elapsed: 0 secs) (at 2015-11-13 18:11:59.021715) ========= 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.NpFlPSwRQX/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.u2RYEBHvJR/Listeners TMPDIR=/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/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:0x0:0x0 using PTY: False build_url:https://queue.taskcluster.net/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.dmg program finished with exit code 0 elapsedTime=0.009844 build_url: 'https://queue.taskcluster.net/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.dmg' ========= master_lag: 0.02 ========= ========= Finished set props: build_url (results: 0, elapsed: 0 secs) (at 2015-11-13 18:11:59.047815) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-11-13 18:11:59.048334) ========= 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.NpFlPSwRQX/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.u2RYEBHvJR/Listeners TMPDIR=/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/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:0x0:0x0 using PTY: False program finished with exit code 0 elapsedTime=0.005257 ========= master_lag: 0.04 ========= ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-11-13 18:11:59.098265) ========= ========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2015-11-13 18:11:59.098702) ========= ========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2015-11-13 18:11:59.099267) ========= ========= Total master_lag: 4.68 =========