builder: fx-team_yosemite_test-other slave: t-yosemite-r5-0104 starttime: 1447466725.21 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.212594) ========= 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.213379) ========= ========= Started set props: basedir (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:25.213747) ========= 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.5lgc4KY1WW/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.TKbTDBAdsE/Listeners TMPDIR=/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/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.006228 basedir: '/builds/slave/test' ========= master_lag: 0.11 ========= ========= Finished set props: basedir (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:25.334496) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:25.334990) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:25.479453) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:25.479781) ========= 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.5lgc4KY1WW/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.TKbTDBAdsE/Listeners TMPDIR=/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/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.023049 ========= master_lag: 0.04 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:25.538082) ========= ========= Started set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:25.538479) ========= 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.538922) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:25.539332) ========= 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.5lgc4KY1WW/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.TKbTDBAdsE/Listeners TMPDIR=/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/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.25, 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% 23.7M=0s 2015-11-13 18:05:25 (23.7 MB/s) - `archiver_client.py' saved [12141/12141] program finished with exit code 0 elapsedTime=0.166276 ========= master_lag: 0.02 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:25.723691) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:25.724063) ========= 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.5lgc4KY1WW/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.TKbTDBAdsE/Listeners TMPDIR=/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/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.096282 ========= master_lag: 0.02 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:25.839480) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:25.839936) ========= 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.5lgc4KY1WW/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.TKbTDBAdsE/Listeners TMPDIR=/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/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,935 truncating revision to first 12 chars 2015-11-13 18:05:25,935 Setting DEBUG logging. 2015-11-13 18:05:25,935 attempt 1/10 2015-11-13 18:05:25,935 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,260 unpacking tar archive at: fx-team-031994a3b4e4/testing/mozharness/ program finished with exit code 0 elapsedTime=0.652557 ========= master_lag: 0.03 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:26.520372) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:26.520761) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:26.539287) ========= ========= Started tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-11-13 18:05:26.539621) ========= 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:26.540118) ========= ========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 6 mins, 49 secs) (at 2015-11-13 18:05:26.540543) ========= /tools/buildbot/bin/python scripts/scripts/talos_script.py --suite other --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', '--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.5lgc4KY1WW/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.TKbTDBAdsE/Listeners TMPDIR=/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/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:26 INFO - MultiFileLogger online at 20151113 18:05:26 in /builds/slave/test 18:05:26 INFO - Run as scripts/scripts/talos_script.py --suite other --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:26 INFO - Dumping config to /builds/slave/test/logs/localconfig.json. 18:05:26 INFO - {'append_to_log': False, 18:05:26 INFO - 'base_work_dir': '/builds/slave/test', 18:05:26 INFO - 'blob_upload_branch': 'Fx-Team', 18:05:26 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt', 18:05:26 INFO - 'branch': 'Fx-Team', 18:05:26 INFO - 'buildbot_json_path': 'buildprops.json', 18:05:26 INFO - 'config_files': ('talos/mac_config.py',), 18:05:26 INFO - 'default_actions': ('clobber', 18:05:26 INFO - 'read-buildbot-config', 18:05:26 INFO - 'download-and-extract', 18:05:26 INFO - 'populate-webroot', 18:05:26 INFO - 'create-virtualenv', 18:05:26 INFO - 'install', 18:05:26 INFO - 'run-tests'), 18:05:26 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 18:05:26 INFO - 'download_minidump_stackwalk': True, 18:05:26 INFO - 'download_symbols': 'ondemand', 18:05:26 INFO - 'exes': {'python': '/tools/buildbot/bin/python', 18:05:26 INFO - 'tooltool.py': '/tools/tooltool.py', 18:05:26 INFO - 'virtualenv': ('/tools/buildbot/bin/python', 18:05:26 INFO - '/tools/misc-python/virtualenv.py')}, 18:05:26 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 18:05:26 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 18:05:26 INFO - 'installer_path': 'installer.exe', 18:05:26 INFO - 'log_level': 'info', 18:05:26 INFO - 'log_name': 'talos', 18:05:26 INFO - 'log_to_console': True, 18:05:26 INFO - 'minidump_stackwalk_path': 'macosx64-minidump_stackwalk', 18:05:26 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/macosx64/releng.manifest', 18:05:26 INFO - 'opt_config_files': (), 18:05:26 INFO - 'pip_index': False, 18:05:26 INFO - 'postflight_run_cmd_suites': ({'architectures': ('32bit', '64bit'), 18:05:26 INFO - 'cmd': ('bash', 18:05:26 INFO - '-c', 18:05:26 INFO - 'screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'), 18:05:26 INFO - 'enabled': True, 18:05:26 INFO - 'halt_on_failure': False, 18:05:26 INFO - 'name': 'check_screen_resolution'},), 18:05:26 INFO - 'preflight_run_cmd_suites': ({'architectures': ('32bit', '64bit'), 18:05:26 INFO - 'cmd': ('bash', 18:05:26 INFO - '-c', 18:05:26 INFO - 'screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'), 18:05:26 INFO - 'enabled': True, 18:05:26 INFO - 'halt_on_failure': False, 18:05:26 INFO - 'name': 'check_screen_resolution'},), 18:05:26 INFO - 'run_cmd_checks_enabled': True, 18:05:26 INFO - 'sps_profile': False, 18:05:26 INFO - 'sps_profile_interval': 0, 18:05:26 INFO - 'suite': 'other', 18:05:26 INFO - 'system_bits': '64', 18:05:26 INFO - 'talos_extra_options': ('--webServer', 'localhost'), 18:05:26 INFO - 'title': 't-yosemite-r5-0104', 18:05:26 INFO - 'tooltool_cache': '/builds/tooltool_cache', 18:05:26 INFO - 'use_talos_json': True, 18:05:26 INFO - 'virtualenv_path': '/builds/slave/test/build/venv', 18:05:26 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 18:05:26 INFO - 'work_dir': 'build'} 18:05:26 INFO - ##### 18:05:26 INFO - ##### Running clobber step. 18:05:26 INFO - ##### 18:05:26 INFO - Running pre-action listener: _resource_record_pre_action 18:05:26 INFO - Running main action method: clobber 18:05:26 INFO - rmtree: /builds/slave/test/build 18:05:26 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1 18:05:30 INFO - Running post-action listener: _resource_record_post_action 18:05:30 INFO - ##### 18:05:30 INFO - ##### Running read-buildbot-config step. 18:05:30 INFO - ##### 18:05:30 INFO - Running pre-action listener: _resource_record_pre_action 18:05:30 INFO - Running main action method: read_buildbot_config 18:05:30 INFO - Using buildbot properties: 18:05:30 INFO - { 18:05:30 INFO - "properties": { 18:05:30 INFO - "buildnumber": 308, 18:05:30 INFO - "product": "firefox", 18:05:30 INFO - "script_repo_revision": "production", 18:05:30 INFO - "builddir": "fx-team_yosemite_test-other", 18:05:30 INFO - "repository": "", 18:05:30 INFO - "buildername": "Rev5 MacOSX Yosemite 10.10 fx-team talos other", 18:05:30 INFO - "buildid": "20151113165331", 18:05:30 INFO - "slavename": "t-yosemite-r5-0104", 18:05:30 INFO - "pgo_build": "False", 18:05:30 INFO - "basedir": "/builds/slave/test", 18:05:30 INFO - "project": "", 18:05:30 INFO - "platform": "yosemite", 18:05:30 INFO - "master": "http://buildbot-master107.bb.releng.scl3.mozilla.com:8201/", 18:05:30 INFO - "slavebuilddir": "test", 18:05:30 INFO - "scheduler": "tests-fx-team-macosx64-talos", 18:05:30 INFO - "branch": "fx-team", 18:05:30 INFO - "repo_path": "integration/fx-team", 18:05:30 INFO - "stage_platform": "macosx64", 18:05:30 INFO - "builduid": "e98c542f62a34925ae0bfbf033bc1410", 18:05:30 INFO - "revision": "031994a3b4e47b1d9ad1c0e4be0b98bdc4e7e242" 18:05:30 INFO - }, 18:05:30 INFO - "sourcestamp": { 18:05:30 INFO - "repository": "", 18:05:30 INFO - "hasPatch": false, 18:05:30 INFO - "project": "", 18:05:30 INFO - "branch": "fx-team-macosx64-talos", 18:05:30 INFO - "changes": [ 18:05:30 INFO - { 18:05:30 INFO - "category": null, 18:05:30 INFO - "files": [ 18:05:30 INFO - { 18:05:30 INFO - "url": null, 18:05:30 INFO - "name": "https://queue.taskcluster.net/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.dmg" 18:05:30 INFO - } 18:05:30 INFO - ], 18:05:30 INFO - "repository": "", 18:05:30 INFO - "rev": "031994a3b4e47b1d9ad1c0e4be0b98bdc4e7e242", 18:05:30 INFO - "who": "nfitzgerald@mozilla.com", 18:05:30 INFO - "when": 1447466669, 18:05:30 INFO - "number": 6661246, 18:05:30 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:30 INFO - "project": "", 18:05:30 INFO - "at": "Fri 13 Nov 2015 18:04:29", 18:05:30 INFO - "branch": "fx-team-macosx64-talos", 18:05:30 INFO - "revlink": "", 18:05:30 INFO - "properties": [ 18:05:30 INFO - [ 18:05:30 INFO - "buildid", 18:05:30 INFO - "20151113165331", 18:05:30 INFO - "Change" 18:05:30 INFO - ], 18:05:30 INFO - [ 18:05:30 INFO - "builduid", 18:05:30 INFO - "e98c542f62a34925ae0bfbf033bc1410", 18:05:30 INFO - "Change" 18:05:30 INFO - ], 18:05:30 INFO - [ 18:05:30 INFO - "pgo_build", 18:05:30 INFO - "False", 18:05:30 INFO - "Change" 18:05:30 INFO - ] 18:05:30 INFO - ], 18:05:30 INFO - "revision": "031994a3b4e47b1d9ad1c0e4be0b98bdc4e7e242" 18:05:30 INFO - } 18:05:30 INFO - ], 18:05:30 INFO - "revision": "031994a3b4e47b1d9ad1c0e4be0b98bdc4e7e242" 18:05:30 INFO - } 18:05:30 INFO - } 18:05:30 INFO - Found installer url https://queue.taskcluster.net/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.dmg. 18:05:30 INFO - Running post-action listener: _resource_record_post_action 18:05:30 INFO - ##### 18:05:30 INFO - ##### Running download-and-extract step. 18:05:30 INFO - ##### 18:05:30 INFO - Running pre-action listener: _resource_record_pre_action 18:05:30 INFO - Running main action method: download_and_extract 18:05:30 INFO - mkdir: /builds/slave/test/build/tests 18:05:30 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:30 INFO - https://queue.taskcluster.net/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/test_packages.json matches https://queue.taskcluster.net 18:05:30 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:30 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/test_packages.json 18:05:30 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:30 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:31 INFO - Downloaded 1149 bytes. 18:05:31 INFO - Reading from file /builds/slave/test/build/test_packages.json 18:05:31 INFO - Using the following test package requirements: 18:05:31 INFO - {u'common': [u'firefox-45.0a1.en-US.mac.common.tests.zip'], 18:05:31 INFO - u'cppunittest': [u'firefox-45.0a1.en-US.mac.common.tests.zip', 18:05:31 INFO - u'firefox-45.0a1.en-US.mac.cppunittest.tests.zip'], 18:05:31 INFO - u'jittest': [u'firefox-45.0a1.en-US.mac.common.tests.zip', 18:05:31 INFO - u'jsshell-mac.zip'], 18:05:31 INFO - u'mochitest': [u'firefox-45.0a1.en-US.mac.common.tests.zip', 18:05:31 INFO - u'firefox-45.0a1.en-US.mac.mochitest.tests.zip'], 18:05:31 INFO - u'mozbase': [u'firefox-45.0a1.en-US.mac.common.tests.zip'], 18:05:31 INFO - u'reftest': [u'firefox-45.0a1.en-US.mac.common.tests.zip', 18:05:31 INFO - u'firefox-45.0a1.en-US.mac.reftest.tests.zip'], 18:05:31 INFO - u'talos': [u'firefox-45.0a1.en-US.mac.common.tests.zip', 18:05:31 INFO - u'firefox-45.0a1.en-US.mac.talos.tests.zip'], 18:05:31 INFO - u'web-platform': [u'firefox-45.0a1.en-US.mac.common.tests.zip', 18:05:31 INFO - u'firefox-45.0a1.en-US.mac.web-platform.tests.zip'], 18:05:31 INFO - u'webapprt': [u'firefox-45.0a1.en-US.mac.common.tests.zip'], 18:05:31 INFO - u'xpcshell': [u'firefox-45.0a1.en-US.mac.common.tests.zip', 18:05:31 INFO - u'firefox-45.0a1.en-US.mac.xpcshell.tests.zip']} 18:05:31 INFO - Downloading packages: [u'firefox-45.0a1.en-US.mac.common.tests.zip'] for test suite category: common 18:05:31 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 18:05:31 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:31 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:31 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:31 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:31 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:32 INFO - Downloaded 17460588 bytes. 18:05:32 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:32 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.mac.common.tests.zip 18:05:32 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:37 INFO - Return code: 0 18:05:37 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:37 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 18:05:37 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:37 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:37 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:37 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:37 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:48 INFO - Downloaded 17460588 bytes. 18:05:48 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:48 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.mac.common.tests.zip 18:05:48 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:53 INFO - Return code: 0 18:05:53 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 18:05:53 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:53 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:53 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:53 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:53 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:55 INFO - Downloaded 11131693 bytes. 18:05:55 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:55 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.mac.talos.tests.zip 18:05:55 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:55 INFO - Return code: 0 18:05:55 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:55 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:55 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:55 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:55 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:55 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:05:59 INFO - The --no-site-packages flag is deprecated; it is now the default behavior. 18:05:59 INFO - Using real prefix '/tools/python27' 18:05:59 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 0x105529490>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x105506228>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7faf0060d2d0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10544c9f0>, '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 0x1051acdb0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1054408c8>, '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.5lgc4KY1WW/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.TKbTDBAdsE/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/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.5lgc4KY1WW/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.TKbTDBAdsE/Listeners', 18:06:04 INFO - 'TMPDIR': '/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/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 - 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:05 INFO - Cleaning up... 18:06:05 INFO - Return code: 0 18:06:05 INFO - Installing psutil>=0.7.1 into virtualenv /builds/slave/test/build/venv 18:06:05 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 18:06:05 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 18:06:05 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:05 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 18:06:05 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 18:06:05 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:05 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 0x105529490>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x105506228>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7faf0060d2d0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10544c9f0>, '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 0x1051acdb0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1054408c8>, '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.5lgc4KY1WW/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.TKbTDBAdsE/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/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:05 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:05 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:05 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.5lgc4KY1WW/Render', 18:06:05 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 18:06:05 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 18:06:05 INFO - 'HOME': '/Users/cltbld', 18:06:05 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 18:06:05 INFO - 'LOGNAME': 'cltbld', 18:06:05 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 18:06:05 INFO - 'MOZ_NO_REMOTE': '1', 18:06:05 INFO - 'NO_EM_RESTART': '1', 18:06:05 INFO - 'PAGER': '/bin/cat', 18:06:05 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 18:06:05 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 18:06:05 INFO - 'PWD': '/builds/slave/test', 18:06:05 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 18:06:05 INFO - 'SHELL': '/bin/bash', 18:06:05 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.TKbTDBAdsE/Listeners', 18:06:05 INFO - 'TMPDIR': '/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/', 18:06:05 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 18:06:05 INFO - 'USER': 'cltbld', 18:06:05 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 18:06:05 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 18:06:05 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 18:06:05 INFO - 'XPC_FLAGS': '0x0', 18:06:05 INFO - 'XPC_SERVICE_NAME': '0', 18:06:05 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:08 INFO - Creating supposed download cache at /builds/slave/test/build/venv/cache 18:06:08 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:08 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/psutil/setup.py) egg_info for package psutil 18:06:08 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 18:06:08 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 18:06:08 INFO - Installing collected packages: psutil 18:06:08 INFO - Running setup.py install for psutil 18:06:08 INFO - building 'psutil._psutil_osx' extension 18:06:08 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:10 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:10 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:10 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:10 INFO - building 'psutil._psutil_posix' extension 18:06:10 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:11 INFO - 1 warning generated. 18:06:11 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:11 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 18:06:11 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 18:06:11 INFO - Successfully installed psutil 18:06:11 INFO - Cleaning up... 18:06:11 INFO - Return code: 0 18:06:11 INFO - Installing mozsystemmonitor==0.0.0 into virtualenv /builds/slave/test/build/venv 18:06:11 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 18:06:11 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 18:06:11 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:11 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 18:06:11 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 18:06:11 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:11 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 0x105529490>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x105506228>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7faf0060d2d0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10544c9f0>, '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 0x1051acdb0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1054408c8>, '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.5lgc4KY1WW/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.TKbTDBAdsE/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/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:11 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:11 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:11 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.5lgc4KY1WW/Render', 18:06:11 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 18:06:11 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 18:06:11 INFO - 'HOME': '/Users/cltbld', 18:06:11 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 18:06:11 INFO - 'LOGNAME': 'cltbld', 18:06:11 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 18:06:11 INFO - 'MOZ_NO_REMOTE': '1', 18:06:11 INFO - 'NO_EM_RESTART': '1', 18:06:11 INFO - 'PAGER': '/bin/cat', 18:06:11 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 18:06:11 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 18:06:11 INFO - 'PWD': '/builds/slave/test', 18:06:11 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 18:06:11 INFO - 'SHELL': '/bin/bash', 18:06:11 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.TKbTDBAdsE/Listeners', 18:06:11 INFO - 'TMPDIR': '/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/', 18:06:11 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 18:06:11 INFO - 'USER': 'cltbld', 18:06:11 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 18:06:11 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 18:06:11 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 18:06:11 INFO - 'XPC_FLAGS': '0x0', 18:06:11 INFO - 'XPC_SERVICE_NAME': '0', 18:06:11 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'} 18:06:11 INFO - Ignoring indexes: https://pypi.python.org/simple/ 18:06:11 INFO - Downloading/unpacking mozsystemmonitor==0.0.0 18:06:11 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:11 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:11 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:11 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:11 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:11 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:14 INFO - Downloading mozsystemmonitor-0.0.tar.gz 18:06:14 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fmozsystemmonitor-0.0.tar.gz 18:06:14 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/mozsystemmonitor/setup.py) egg_info for package mozsystemmonitor 18:06:14 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:14 INFO - Installing collected packages: mozsystemmonitor 18:06:14 INFO - Running setup.py install for mozsystemmonitor 18:06:14 INFO - Successfully installed mozsystemmonitor 18:06:14 INFO - Cleaning up... 18:06:14 INFO - Return code: 0 18:06:14 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv 18:06:14 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:14 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 18:06:14 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:14 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:14 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 18:06:14 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:14 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 0x105529490>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x105506228>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7faf0060d2d0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10544c9f0>, '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 0x1051acdb0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1054408c8>, '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.5lgc4KY1WW/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.TKbTDBAdsE/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/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:14 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:14 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:14 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.5lgc4KY1WW/Render', 18:06:14 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 18:06:14 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 18:06:14 INFO - 'HOME': '/Users/cltbld', 18:06:14 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 18:06:14 INFO - 'LOGNAME': 'cltbld', 18:06:14 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 18:06:14 INFO - 'MOZ_NO_REMOTE': '1', 18:06:14 INFO - 'NO_EM_RESTART': '1', 18:06:14 INFO - 'PAGER': '/bin/cat', 18:06:14 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 18:06:14 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 18:06:14 INFO - 'PWD': '/builds/slave/test', 18:06:14 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 18:06:14 INFO - 'SHELL': '/bin/bash', 18:06:14 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.TKbTDBAdsE/Listeners', 18:06:14 INFO - 'TMPDIR': '/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/', 18:06:14 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 18:06:14 INFO - 'USER': 'cltbld', 18:06:14 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 18:06:14 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 18:06:14 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 18:06:14 INFO - 'XPC_FLAGS': '0x0', 18:06:14 INFO - 'XPC_SERVICE_NAME': '0', 18:06:14 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'} 18:06:14 INFO - Ignoring indexes: https://pypi.python.org/simple/ 18:06:14 INFO - Downloading/unpacking blobuploader==1.2.4 18:06:14 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:14 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:14 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:14 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:14 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:14 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 blobuploader-1.2.4.tar.gz 18:06:17 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:17 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blobuploader/setup.py) egg_info for package blobuploader 18:06:17 INFO - Downloading/unpacking requests==1.2.3. (from blobuploader==1.2.4) 18:06:17 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:17 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 - 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:17 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:17 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:17 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:18 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:18 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests 18:06:18 INFO - Downloading/unpacking docopt==0.6.1 (from blobuploader==1.2.4) 18:06:18 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:18 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:18 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:18 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:18 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:18 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:19 INFO - Downloading docopt-0.6.1.tar.gz 18:06:19 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:19 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/docopt/setup.py) egg_info for package docopt 18:06:19 INFO - Installing collected packages: blobuploader, requests, docopt 18:06:19 INFO - Running setup.py install for blobuploader 18:06:19 INFO - changing mode of build/scripts-2.7/blobberc.py from 664 to 775 18:06:19 INFO - changing mode of /builds/slave/test/build/venv/bin/blobberc.py to 775 18:06:19 INFO - Running setup.py install for requests 18:06:19 INFO - Running setup.py install for docopt 18:06:20 INFO - Successfully installed blobuploader requests docopt 18:06:20 INFO - Cleaning up... 18:06:20 INFO - Return code: 0 18:06:20 INFO - Installing None into virtualenv /builds/slave/test/build/venv 18:06:20 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:20 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 18:06:20 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:20 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:20 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 18:06:20 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:20 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 0x105529490>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x105506228>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7faf0060d2d0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10544c9f0>, '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 0x1051acdb0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1054408c8>, '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.5lgc4KY1WW/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.TKbTDBAdsE/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/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:20 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:20 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:20 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.5lgc4KY1WW/Render', 18:06:20 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 18:06:20 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 18:06:20 INFO - 'HOME': '/Users/cltbld', 18:06:20 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 18:06:20 INFO - 'LOGNAME': 'cltbld', 18:06:20 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 18:06:20 INFO - 'MOZ_NO_REMOTE': '1', 18:06:20 INFO - 'NO_EM_RESTART': '1', 18:06:20 INFO - 'PAGER': '/bin/cat', 18:06:20 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 18:06:20 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 18:06:20 INFO - 'PWD': '/builds/slave/test', 18:06:20 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 18:06:20 INFO - 'SHELL': '/bin/bash', 18:06:20 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.TKbTDBAdsE/Listeners', 18:06:20 INFO - 'TMPDIR': '/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/', 18:06:20 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 18:06:20 INFO - 'USER': 'cltbld', 18:06:20 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 18:06:20 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 18:06:20 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 18:06:20 INFO - 'XPC_FLAGS': '0x0', 18:06:20 INFO - 'XPC_SERVICE_NAME': '0', 18:06:20 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'} 18:06:20 INFO - Ignoring indexes: https://pypi.python.org/simple/ 18:06:20 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 18:06:20 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-30mY2l-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 18:06:20 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 18:06:20 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-QnRxgy-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 18:06:20 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 18:06:20 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-dHFGja-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 18:06:21 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 18:06:21 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-aHD0JR-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 18:06:21 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 18:06:21 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-q6Vraz-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 18:06:21 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 18:06:21 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-re4Ot6-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 18:06:21 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 18:06:21 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-IqPszp-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 18:06:21 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 18:06:21 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-pr_PI8-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 18:06:21 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 18:06:21 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-YbJWHs-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 18:06:21 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 18:06:21 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-qG3CKj-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 18:06:21 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 18:06:21 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-lkdGQh-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 18:06:22 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 18:06:22 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-chUcdw-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 18:06:22 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 18:06:22 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-bLdPk8-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 18:06:22 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 18:06:22 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-0jzprL-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 18:06:22 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 18:06:22 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-EEb55w-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 18:06:22 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 18:06:22 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-6cyKjj-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 18:06:22 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 18:06:22 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-rQTPCb-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 18:06:22 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion 18:06:22 INFO - Running setup.py install for manifestparser 18:06:23 INFO - Installing manifestparser script to /builds/slave/test/build/venv/bin 18:06:23 INFO - Running setup.py install for mozcrash 18:06:23 INFO - Running setup.py install for mozdebug 18:06:23 INFO - Running setup.py install for mozdevice 18:06:23 INFO - Installing sutini script to /builds/slave/test/build/venv/bin 18:06:23 INFO - Installing dm script to /builds/slave/test/build/venv/bin 18:06:23 INFO - Running setup.py install for mozfile 18:06:23 INFO - Running setup.py install for mozhttpd 18:06:24 INFO - Installing mozhttpd script to /builds/slave/test/build/venv/bin 18:06:24 INFO - Running setup.py install for mozinfo 18:06:24 INFO - Installing mozinfo script to /builds/slave/test/build/venv/bin 18:06:24 INFO - Running setup.py install for mozInstall 18:06:24 INFO - Installing moz_remove_from_system script to /builds/slave/test/build/venv/bin 18:06:24 INFO - Installing mozuninstall script to /builds/slave/test/build/venv/bin 18:06:24 INFO - Installing mozinstall script to /builds/slave/test/build/venv/bin 18:06:24 INFO - Installing moz_add_to_system script to /builds/slave/test/build/venv/bin 18:06:24 INFO - Running setup.py install for mozleak 18:06:24 INFO - Running setup.py install for mozlog 18:06:24 INFO - Installing structlog script to /builds/slave/test/build/venv/bin 18:06:24 INFO - Running setup.py install for moznetwork 18:06:25 INFO - Installing moznetwork script to /builds/slave/test/build/venv/bin 18:06:25 INFO - Running setup.py install for mozprocess 18:06:25 INFO - Running setup.py install for mozprofile 18:06:25 INFO - Installing mozprofile script to /builds/slave/test/build/venv/bin 18:06:25 INFO - Installing diff-profiles script to /builds/slave/test/build/venv/bin 18:06:25 INFO - Installing view-profile script to /builds/slave/test/build/venv/bin 18:06:25 INFO - Running setup.py install for mozrunner 18:06:25 INFO - Installing mozrunner script to /builds/slave/test/build/venv/bin 18:06:25 INFO - Running setup.py install for mozscreenshot 18:06:25 INFO - Running setup.py install for moztest 18:06:26 INFO - Running setup.py install for mozversion 18:06:26 INFO - Installing mozversion script to /builds/slave/test/build/venv/bin 18:06:26 INFO - Successfully installed manifestparser mozcrash mozdebug mozdevice mozfile mozhttpd mozinfo mozInstall mozleak mozlog moznetwork mozprocess mozprofile mozrunner mozscreenshot moztest mozversion 18:06:26 INFO - Cleaning up... 18:06:26 INFO - Return code: 0 18:06:26 INFO - Installing None into virtualenv /builds/slave/test/build/venv 18:06:26 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 18:06:26 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 18:06:26 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:26 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 18:06:26 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 18:06:26 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:26 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 0x105529490>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x105506228>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7faf0060d2d0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10544c9f0>, '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 0x1051acdb0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1054408c8>, '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.5lgc4KY1WW/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.TKbTDBAdsE/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/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:26 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:26 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:26 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.5lgc4KY1WW/Render', 18:06:26 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 18:06:26 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 18:06:26 INFO - 'HOME': '/Users/cltbld', 18:06:26 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 18:06:26 INFO - 'LOGNAME': 'cltbld', 18:06:26 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 18:06:26 INFO - 'MOZ_NO_REMOTE': '1', 18:06:26 INFO - 'NO_EM_RESTART': '1', 18:06:26 INFO - 'PAGER': '/bin/cat', 18:06:26 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 18:06:26 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 18:06:26 INFO - 'PWD': '/builds/slave/test', 18:06:26 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 18:06:26 INFO - 'SHELL': '/bin/bash', 18:06:26 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.TKbTDBAdsE/Listeners', 18:06:26 INFO - 'TMPDIR': '/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/', 18:06:26 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 18:06:26 INFO - 'USER': 'cltbld', 18:06:26 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 18:06:26 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 18:06:26 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 18:06:26 INFO - 'XPC_FLAGS': '0x0', 18:06:26 INFO - 'XPC_SERVICE_NAME': '0', 18:06:26 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'} 18:06:26 INFO - Ignoring indexes: https://pypi.python.org/simple/ 18:06:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 18:06:26 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-EFFqPn-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 18:06:26 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:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 18:06:26 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-XR_PuC-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 18:06:26 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:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 18:06:26 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-Nhmh1E-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 18:06:27 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:27 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 18:06:27 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-KbllgA-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 18:06:27 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:27 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 18:06:27 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-1vDn6f-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 18:06:27 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:27 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 18:06:27 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-OrE155-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 18:06:27 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:27 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 18:06:27 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-L9MYv1-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 18:06:27 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:27 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 18:06:27 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-Ugnxul-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 18:06:27 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:27 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 18:06:27 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-_Po4O_-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 18:06:27 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:27 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 18:06:27 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-bZ6Hcc-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 18:06:28 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:28 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 18:06:28 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-7G3xsl-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 18:06:28 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:28 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 18:06:28 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-j7fmIO-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 18:06:28 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:28 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 18:06:28 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-vBdCVR-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 18:06:28 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:28 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 18:06:28 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-gVaJEd-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 18:06:28 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:28 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 18:06:28 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-EEK_7o-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 18:06:28 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:28 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 18:06:28 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-qwj1yg-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 18:06:28 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:28 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 18:06:28 INFO - Running setup.py (path:/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/pip-QhcXwh-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 18:06:29 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:29 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: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.16->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2)) 18:06:29 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:29 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:29 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:29 INFO - Downloading/unpacking blessings>=1.3 (from mozlog==3.0->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 18:06:29 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:29 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:29 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:29 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:29 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:29 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:31 INFO - Downloading blessings-1.5.1.tar.gz 18:06:31 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:31 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blessings/setup.py) egg_info for package blessings 18:06:31 INFO - Installing collected packages: blessings 18:06:31 INFO - Running setup.py install for blessings 18:06:32 INFO - Successfully installed blessings 18:06:32 INFO - Cleaning up... 18:06:32 INFO - Return code: 0 18:06:32 INFO - Done creating virtualenv /builds/slave/test/build/venv. 18:06:32 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 18:06:32 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 18:06:32 INFO - Reading from file tmpfile_stdout 18:06:32 INFO - Current package versions: 18:06:32 INFO - blessings == 1.5.1 18:06:32 INFO - blobuploader == 1.2.4 18:06:32 INFO - docopt == 0.6.1 18:06:32 INFO - manifestparser == 1.1 18:06:32 INFO - mozInstall == 1.12 18:06:32 INFO - mozcrash == 0.16 18:06:32 INFO - mozdebug == 0.1 18:06:32 INFO - mozdevice == 0.47 18:06:32 INFO - mozfile == 1.2 18:06:32 INFO - mozhttpd == 0.7 18:06:32 INFO - mozinfo == 0.9 18:06:32 INFO - mozleak == 0.1 18:06:32 INFO - mozlog == 3.0 18:06:32 INFO - moznetwork == 0.27 18:06:32 INFO - mozprocess == 0.22 18:06:32 INFO - mozprofile == 0.27 18:06:32 INFO - mozrunner == 6.11 18:06:32 INFO - mozscreenshot == 0.1 18:06:32 INFO - mozsystemmonitor == 0.0 18:06:32 INFO - moztest == 0.7 18:06:32 INFO - mozversion == 1.4 18:06:32 INFO - psutil == 3.1.1 18:06:32 INFO - requests == 1.2.3 18:06:32 INFO - wsgiref == 0.1.2 18:06:32 INFO - Installing None into virtualenv /builds/slave/test/build/venv 18:06:32 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:32 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 18:06:32 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:32 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:32 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 18:06:32 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 18:06:32 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 0x105529490>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x105506228>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7faf0060d2d0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10544c9f0>, '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 0x1051acdb0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1054408c8>, '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.5lgc4KY1WW/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.TKbTDBAdsE/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/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:32 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:32 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:32 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.5lgc4KY1WW/Render', 18:06:32 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 18:06:32 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 18:06:32 INFO - 'HOME': '/Users/cltbld', 18:06:32 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 18:06:32 INFO - 'LOGNAME': 'cltbld', 18:06:32 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 18:06:32 INFO - 'MOZ_NO_REMOTE': '1', 18:06:32 INFO - 'NO_EM_RESTART': '1', 18:06:32 INFO - 'PAGER': '/bin/cat', 18:06:32 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 18:06:32 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 18:06:32 INFO - 'PWD': '/builds/slave/test', 18:06:32 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 18:06:32 INFO - 'SHELL': '/bin/bash', 18:06:32 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.TKbTDBAdsE/Listeners', 18:06:32 INFO - 'TMPDIR': '/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/', 18:06:32 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 18:06:32 INFO - 'USER': 'cltbld', 18:06:32 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 18:06:32 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 18:06:32 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 18:06:32 INFO - 'XPC_FLAGS': '0x0', 18:06:32 INFO - 'XPC_SERVICE_NAME': '0', 18:06:32 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'} 18:06:32 INFO - Ignoring indexes: https://pypi.python.org/simple/ 18:06:32 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:32 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:32 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:32 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:32 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:32 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:32 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:32 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:32 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:32 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:32 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:32 INFO - Cleaning up... 18:06:32 INFO - Return code: 0 18:06:32 INFO - Running post-action listener: _resource_record_post_action 18:06:32 INFO - Running post-action listener: _start_resource_monitoring 18:06:32 INFO - Starting resource monitoring. 18:06:32 INFO - ##### 18:06:32 INFO - ##### Running install step. 18:06:32 INFO - ##### 18:06:32 INFO - Running pre-action listener: _resource_record_pre_action 18:06:32 INFO - Running main action method: install 18:06:32 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 18:06:32 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 18:06:33 INFO - Reading from file tmpfile_stdout 18:06:33 INFO - Detecting whether we're running mozinstall >=1.0... 18:06:33 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h'] 18:06:33 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h 18:06:33 INFO - Reading from file tmpfile_stdout 18:06:33 INFO - Output received: 18:06:33 INFO - Usage: mozinstall [options] installer 18:06:33 INFO - Options: 18:06:33 INFO - -h, --help show this help message and exit 18:06:33 INFO - -d DEST, --destination=DEST 18:06:33 INFO - Directory to install application into. [default: 18:06:33 INFO - "/builds/slave/test"] 18:06:33 INFO - --app=APP Application being installed. [default: firefox] 18:06:33 INFO - mkdir: /builds/slave/test/build/application 18:06:33 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:33 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:14 INFO - Reading from file tmpfile_stdout 18:07:14 INFO - Output received: 18:07:14 INFO - /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox 18:07:14 INFO - Running post-action listener: _resource_record_post_action 18:07:14 INFO - ##### 18:07:14 INFO - ##### Running run-tests step. 18:07:14 INFO - ##### 18:07:14 INFO - Running pre-action listener: _resource_record_pre_action 18:07:14 INFO - Running main action method: run_tests 18:07:14 INFO - Running pre test command check_screen_resolution with 'bash -c screenresolution get && screenresolution list && system_profiler SPDisplaysDataType' 18:07:14 INFO - Running command: ['bash', '-c', 'screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'] in /builds/slave/test/build 18:07:14 INFO - Copy/paste: bash -c "screenresolution get && screenresolution list && system_profiler SPDisplaysDataType" 18:07:14 INFO - 2015-11-13 18:07:14.932 screenresolution[1624:8001] starting screenresolution argv=screenresolution get 18:07:14 INFO - 2015-11-13 18:07:14.942 screenresolution[1624:8001] Display 0: 1600x1200x32@60 18:07:14 INFO - 2015-11-13 18:07:14.949 screenresolution[1625:8003] starting screenresolution argv=screenresolution list 18:07:14 INFO - Available Modes on Display 0 18:07:14 INFO - 1600x1200x32@60 1152x870x32@75 1280x1024x32@75 18:07:14 INFO - 1024x768x32@75 1024x768x32@70 1024x768x32@60 18:07:14 INFO - 800x600x32@75 800x600x32@60 640x480x32@75 18:07:14 INFO - 640x480x32@60 1280x1024x32@60 1280x960x32@60 18:07:15 INFO - 1280x960x32@75 1344x1008x32@60 Graphics/Displays: 18:07:15 INFO - Intel HD Graphics 3000: 18:07:15 INFO - Chipset Model: Intel HD Graphics 3000 18:07:15 INFO - Type: GPU 18:07:15 INFO - Bus: Built-In 18:07:15 INFO - VRAM (Total): 512 MB 18:07:15 INFO - VRAM (Dynamic, Max): 10 18:07:15 INFO - Vendor: Intel (0x8086) 18:07:15 INFO - Device ID: 0x0116 18:07:15 INFO - Revision ID: 0x0009 18:07:15 INFO - Displays: 18:07:15 INFO - Display: 18:07:15 INFO - Resolution: 1600 x 1200 @ 60 Hz 18:07:15 INFO - Pixel Depth: 32-Bit Color (ARGB8888) 18:07:15 INFO - Display Serial Number: 1600x1200 60 18:07:15 INFO - Main Display: Yes 18:07:15 INFO - Mirror: Off 18:07:15 INFO - Online: Yes 18:07:15 INFO - Rotation: Supported 18:07:15 INFO - Return code: 0 18:07:15 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version'] 18:07:15 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version 18:07:15 INFO - Python 2.7.3 18:07:15 INFO - Return code: 0 18:07:15 INFO - grabbing minidump binary from tooltool 18:07:15 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:15 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 0x10544c9f0>, '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 0x1051acdb0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1054408c8>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1 18:07:15 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:15 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:15 INFO - INFO - File macosx64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache 18:07:15 INFO - Return code: 0 18:07:15 INFO - Chmoding /builds/slave/test/build/macosx64-minidump_stackwalk to 0755 18:07:15 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir 18:07:15 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir 18:07:15 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/macosx64-minidump_stackwalk 18:07:15 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir 18:07:15 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', '--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-0104', '--webServer', 'localhost'] in /builds/slave/test/build 18:07:15 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 --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-0104 --webServer localhost 18:07:15 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.5lgc4KY1WW/Render', 18:07:15 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 18:07:15 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 18:07:15 INFO - 'HOME': '/Users/cltbld', 18:07:15 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 18:07:15 INFO - 'LOGNAME': 'cltbld', 18:07:15 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 18:07:15 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/macosx64-minidump_stackwalk', 18:07:15 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 18:07:15 INFO - 'MOZ_NO_REMOTE': '1', 18:07:15 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 18:07:15 INFO - 'NO_EM_RESTART': '1', 18:07:15 INFO - 'PAGER': '/bin/cat', 18:07:15 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:15 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 18:07:15 INFO - 'PWD': '/builds/slave/test', 18:07:15 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 18:07:15 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 18:07:15 INFO - 'SHELL': '/bin/bash', 18:07:15 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.TKbTDBAdsE/Listeners', 18:07:15 INFO - 'TMPDIR': '/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/', 18:07:15 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 18:07:15 INFO - 'USER': 'cltbld', 18:07:15 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 18:07:15 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 18:07:15 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 18:07:15 INFO - 'XPC_FLAGS': '0x0', 18:07:15 INFO - 'XPC_SERVICE_NAME': '0', 18:07:15 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'} 18:07:15 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', '--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-0104', '--webServer', 'localhost'] with output_timeout 3600 18:07:15 INFO - mozversion INFO | application_buildid: 20151113165331 18:07:15 INFO - mozversion INFO | application_changeset: 031994a3b4e47b1d9ad1c0e4be0b98bdc4e7e242 18:07:15 INFO - mozversion INFO | application_display_name: Nightly 18:07:15 INFO - mozversion INFO | application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384} 18:07:15 INFO - mozversion INFO | application_name: Firefox 18:07:15 INFO - mozversion INFO | application_remotingname: firefox 18:07:15 INFO - mozversion INFO | application_repository: https://hg.mozilla.org/integration/fx-team 18:07:15 INFO - mozversion INFO | application_vendor: Mozilla 18:07:15 INFO - mozversion INFO | application_version: 45.0a1 18:07:15 INFO - mozversion INFO | platform_buildid: 20151113165331 18:07:15 INFO - mozversion INFO | platform_changeset: 031994a3b4e47b1d9ad1c0e4be0b98bdc4e7e242 18:07:15 INFO - mozversion INFO | platform_repository: https://hg.mozilla.org/integration/fx-team 18:07:15 INFO - mozversion INFO | platform_version: 45.0a1 18:07:15 INFO - 2015-11-13 18:07:15,675 DEBUG : using testdate: 1447466835 18:07:15 INFO - 2015-11-13 18:07:15,675 DEBUG : actual date: 1447466835 18:07:15 INFO - 2015-11-13 18:07:15,724 INFO : starting webserver on 'localhost:49265' 18:07:15 INFO - 2015-11-13 18:07:15,726 INFO : Starting test suite t-yosemite-r5-0104 18:07:15 INFO - 2015-11-13 18:07:15,726 INFO : Starting test a11yr 18:07:15 INFO - 2015-11-13 18:07:15,726 DEBUG : operating with platform_type : mac_ 18:07:15 INFO - 2015-11-13 18:07:15,727 INFO : Initialising browser for a11yr test... 18:07:15 INFO - 2015-11-13 18:07:15,743 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpLtg6Aw/profile http://localhost:49265/getInfo.html 18:07:19 INFO - 2015-11-13 18:07:19,913 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 18:07:19 INFO - 2015-11-13 18:07:19,913 DEBUG : BROWSER_OUTPUT: colorDepth:24 18:07:19 INFO - 2015-11-13 18:07:19,913 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/689 18:07:19 INFO - 2015-11-13 18:07:19,913 DEBUG : BROWSER_OUTPUT: __metrics 18:07:19 INFO - 2015-11-13 18:07:19,929 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 18:07:20 INFO - 2015-11-13 18:07:20,694 INFO : Browser initialized. 18:07:20 INFO - 2015-11-13 18:07:20,695 INFO : Running cycle 1/1 for a11yr test... 18:07:20 INFO - 2015-11-13 18:07:20,695 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpLtg6Aw/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/a11y/a11y.manifest.develop -tpchrome -tpmozafterpaint -tpnoisy -tpcycles 1 -tppagecycles 25 18:07:32 INFO - 2015-11-13 18:07:32,857 DEBUG : BROWSER_OUTPUT: RSS: Main: 229601280 18:07:32 INFO - 2015-11-13 18:07:32,858 DEBUG : BROWSER_OUTPUT: 18:07:34 INFO - 2015-11-13 18:07:34,149 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:34 INFO - 2015-11-13 18:07:34,765 DEBUG : BROWSER_OUTPUT: RSS: Main: 278257664 18:07:34 INFO - 2015-11-13 18:07:34,765 DEBUG : BROWSER_OUTPUT: 18:07:36 INFO - 2015-11-13 18:07:36,117 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:36 INFO - 2015-11-13 18:07:36,807 DEBUG : BROWSER_OUTPUT: RSS: Main: 296177664 18:07:36 INFO - 2015-11-13 18:07:36,808 DEBUG : BROWSER_OUTPUT: 18:07:38 INFO - 2015-11-13 18:07:38,153 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:38 INFO - 2015-11-13 18:07:38,841 DEBUG : BROWSER_OUTPUT: RSS: Main: 298663936 18:07:38 INFO - 2015-11-13 18:07:38,841 DEBUG : BROWSER_OUTPUT: 18:07:40 INFO - 2015-11-13 18:07:40,195 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:40 INFO - 2015-11-13 18:07:40,886 DEBUG : BROWSER_OUTPUT: RSS: Main: 299823104 18:07:40 INFO - 2015-11-13 18:07:40,886 DEBUG : BROWSER_OUTPUT: 18:07:42 INFO - 2015-11-13 18:07:42,202 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:42 INFO - 2015-11-13 18:07:42,946 DEBUG : BROWSER_OUTPUT: RSS: Main: 298831872 18:07:42 INFO - 2015-11-13 18:07:42,946 DEBUG : BROWSER_OUTPUT: 18:07:44 INFO - 2015-11-13 18:07:44,294 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:44 INFO - 2015-11-13 18:07:44,979 DEBUG : BROWSER_OUTPUT: RSS: Main: 300154880 18:07:44 INFO - 2015-11-13 18:07:44,979 DEBUG : BROWSER_OUTPUT: 18:07:46 INFO - 2015-11-13 18:07:46,389 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:47 INFO - 2015-11-13 18:07:47,077 DEBUG : BROWSER_OUTPUT: RSS: Main: 302084096 18:07:47 INFO - 2015-11-13 18:07:47,077 DEBUG : BROWSER_OUTPUT: 18:07:48 INFO - 2015-11-13 18:07:48,425 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:49 INFO - 2015-11-13 18:07:49,113 DEBUG : BROWSER_OUTPUT: RSS: Main: 301129728 18:07:49 INFO - 2015-11-13 18:07:49,113 DEBUG : BROWSER_OUTPUT: 18:07:50 INFO - 2015-11-13 18:07:50,466 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:51 INFO - 2015-11-13 18:07:51,157 DEBUG : BROWSER_OUTPUT: RSS: Main: 300961792 18:07:51 INFO - 2015-11-13 18:07:51,157 DEBUG : BROWSER_OUTPUT: 18:07:52 INFO - 2015-11-13 18:07:52,509 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:53 INFO - 2015-11-13 18:07:53,203 DEBUG : BROWSER_OUTPUT: RSS: Main: 301408256 18:07:53 INFO - 2015-11-13 18:07:53,203 DEBUG : BROWSER_OUTPUT: 18:07:54 INFO - 2015-11-13 18:07:54,575 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:55 INFO - 2015-11-13 18:07:55,277 DEBUG : BROWSER_OUTPUT: RSS: Main: 300462080 18:07:55 INFO - 2015-11-13 18:07:55,277 DEBUG : BROWSER_OUTPUT: 18:07:56 INFO - 2015-11-13 18:07:56,559 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:57 INFO - 2015-11-13 18:07:57,259 DEBUG : BROWSER_OUTPUT: RSS: Main: 302620672 18:07:57 INFO - 2015-11-13 18:07:57,259 DEBUG : BROWSER_OUTPUT: 18:07:58 INFO - 2015-11-13 18:07:58,607 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:59 INFO - 2015-11-13 18:07:59,313 DEBUG : BROWSER_OUTPUT: RSS: Main: 303759360 18:07:59 INFO - 2015-11-13 18:07:59,313 DEBUG : BROWSER_OUTPUT: 18:08:00 INFO - 2015-11-13 18:08:00,676 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:08:01 INFO - 2015-11-13 18:08:01,376 DEBUG : BROWSER_OUTPUT: RSS: Main: 301457408 18:08:01 INFO - 2015-11-13 18:08:01,376 DEBUG : BROWSER_OUTPUT: 18:08:02 INFO - 2015-11-13 18:08:02,736 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:08:03 INFO - 2015-11-13 18:08:03,434 DEBUG : BROWSER_OUTPUT: RSS: Main: 302977024 18:08:03 INFO - 2015-11-13 18:08:03,435 DEBUG : BROWSER_OUTPUT: 18:08:04 INFO - 2015-11-13 18:08:04,687 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:08:05 INFO - 2015-11-13 18:08:05,377 DEBUG : BROWSER_OUTPUT: RSS: Main: 302174208 18:08:05 INFO - 2015-11-13 18:08:05,377 DEBUG : BROWSER_OUTPUT: 18:08:06 INFO - 2015-11-13 18:08:06,792 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:08:07 INFO - 2015-11-13 18:08:07,494 DEBUG : BROWSER_OUTPUT: RSS: Main: 302903296 18:08:07 INFO - 2015-11-13 18:08:07,494 DEBUG : BROWSER_OUTPUT: 18:08:08 INFO - 2015-11-13 18:08:08,910 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:08:09 INFO - 2015-11-13 18:08:09,602 DEBUG : BROWSER_OUTPUT: RSS: Main: 303116288 18:08:09 INFO - 2015-11-13 18:08:09,602 DEBUG : BROWSER_OUTPUT: 18:08:10 INFO - 2015-11-13 18:08:10,949 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:08:11 INFO - 2015-11-13 18:08:11,642 DEBUG : BROWSER_OUTPUT: RSS: Main: 303591424 18:08:11 INFO - 2015-11-13 18:08:11,643 DEBUG : BROWSER_OUTPUT: 18:08:12 INFO - 2015-11-13 18:08:12,930 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:13 INFO - 2015-11-13 18:08:13,627 DEBUG : BROWSER_OUTPUT: RSS: Main: 303144960 18:08:13 INFO - 2015-11-13 18:08:13,628 DEBUG : BROWSER_OUTPUT: 18:08:15 INFO - 2015-11-13 18:08:15,018 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:15 INFO - 2015-11-13 18:08:15,707 DEBUG : BROWSER_OUTPUT: RSS: Main: 304640000 18:08:15 INFO - 2015-11-13 18:08:15,707 DEBUG : BROWSER_OUTPUT: 18:08:17 INFO - 2015-11-13 18:08:17,086 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:17 INFO - 2015-11-13 18:08:17,787 DEBUG : BROWSER_OUTPUT: RSS: Main: 304377856 18:08:17 INFO - 2015-11-13 18:08:17,787 DEBUG : BROWSER_OUTPUT: 18:08:19 INFO - 2015-11-13 18:08:19,142 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:19 INFO - 2015-11-13 18:08:19,846 DEBUG : BROWSER_OUTPUT: RSS: Main: 304488448 18:08:19 INFO - 2015-11-13 18:08:19,847 DEBUG : BROWSER_OUTPUT: 18:08:21 INFO - 2015-11-13 18:08:21,221 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:21 INFO - 2015-11-13 18:08:21,924 DEBUG : BROWSER_OUTPUT: RSS: Main: 307695616 18:08:21 INFO - 2015-11-13 18:08:21,924 DEBUG : BROWSER_OUTPUT: 18:08:23 INFO - 2015-11-13 18:08:23,334 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:23 INFO - 2015-11-13 18:08:23,356 DEBUG : BROWSER_OUTPUT: 1447466903355 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:24 INFO - 2015-11-13 18:08:24,064 DEBUG : BROWSER_OUTPUT: RSS: Main: 308629504 18:08:24 INFO - 2015-11-13 18:08:24,065 DEBUG : BROWSER_OUTPUT: 18:08:24 INFO - 2015-11-13 18:08:24,874 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:25 INFO - 2015-11-13 18:08:25,467 DEBUG : BROWSER_OUTPUT: RSS: Main: 307453952 18:08:25 INFO - 2015-11-13 18:08:25,467 DEBUG : BROWSER_OUTPUT: 18:08:26 INFO - 2015-11-13 18:08:26,257 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:26 INFO - 2015-11-13 18:08:26,840 DEBUG : BROWSER_OUTPUT: RSS: Main: 307429376 18:08:26 INFO - 2015-11-13 18:08:26,840 DEBUG : BROWSER_OUTPUT: 18:08:27 INFO - 2015-11-13 18:08:27,615 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:28 INFO - 2015-11-13 18:08:28,201 DEBUG : BROWSER_OUTPUT: RSS: Main: 307605504 18:08:28 INFO - 2015-11-13 18:08:28,201 DEBUG : BROWSER_OUTPUT: 18:08:28 INFO - 2015-11-13 18:08:28,948 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:29 INFO - 2015-11-13 18:08:29,533 DEBUG : BROWSER_OUTPUT: RSS: Main: 307499008 18:08:29 INFO - 2015-11-13 18:08:29,533 DEBUG : BROWSER_OUTPUT: 18:08:30 INFO - 2015-11-13 18:08:30,297 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:30 INFO - 2015-11-13 18:08:30,887 DEBUG : BROWSER_OUTPUT: RSS: Main: 308289536 18:08:30 INFO - 2015-11-13 18:08:30,887 DEBUG : BROWSER_OUTPUT: 18:08:31 INFO - 2015-11-13 18:08:31,670 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:32 INFO - 2015-11-13 18:08:32,269 DEBUG : BROWSER_OUTPUT: RSS: Main: 308989952 18:08:32 INFO - 2015-11-13 18:08:32,269 DEBUG : BROWSER_OUTPUT: 18:08:33 INFO - 2015-11-13 18:08:33,041 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:33 INFO - 2015-11-13 18:08:33,622 DEBUG : BROWSER_OUTPUT: RSS: Main: 307081216 18:08:33 INFO - 2015-11-13 18:08:33,622 DEBUG : BROWSER_OUTPUT: 18:08:34 INFO - 2015-11-13 18:08:34,391 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:34 INFO - 2015-11-13 18:08:34,980 DEBUG : BROWSER_OUTPUT: RSS: Main: 302125056 18:08:34 INFO - 2015-11-13 18:08:34,980 DEBUG : BROWSER_OUTPUT: 18:08:35 INFO - 2015-11-13 18:08:35,714 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:36 INFO - 2015-11-13 18:08:36,301 DEBUG : BROWSER_OUTPUT: RSS: Main: 302637056 18:08:36 INFO - 2015-11-13 18:08:36,301 DEBUG : BROWSER_OUTPUT: 18:08:37 INFO - 2015-11-13 18:08:37,079 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:37 INFO - 2015-11-13 18:08:37,673 DEBUG : BROWSER_OUTPUT: RSS: Main: 303415296 18:08:37 INFO - 2015-11-13 18:08:37,673 DEBUG : BROWSER_OUTPUT: 18:08:38 INFO - 2015-11-13 18:08:38,461 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:39 INFO - 2015-11-13 18:08:39,055 DEBUG : BROWSER_OUTPUT: RSS: Main: 302010368 18:08:39 INFO - 2015-11-13 18:08:39,055 DEBUG : BROWSER_OUTPUT: 18:08:39 INFO - 2015-11-13 18:08:39,797 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:40 INFO - 2015-11-13 18:08:40,384 DEBUG : BROWSER_OUTPUT: RSS: Main: 302678016 18:08:40 INFO - 2015-11-13 18:08:40,384 DEBUG : BROWSER_OUTPUT: 18:08:41 INFO - 2015-11-13 18:08:41,156 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:41 INFO - 2015-11-13 18:08:41,745 DEBUG : BROWSER_OUTPUT: RSS: Main: 303611904 18:08:41 INFO - 2015-11-13 18:08:41,745 DEBUG : BROWSER_OUTPUT: 18:08:42 INFO - 2015-11-13 18:08:42,518 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:43 INFO - 2015-11-13 18:08:43,120 DEBUG : BROWSER_OUTPUT: RSS: Main: 304091136 18:08:43 INFO - 2015-11-13 18:08:43,120 DEBUG : BROWSER_OUTPUT: 18:08:43 INFO - 2015-11-13 18:08:43,895 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:44 INFO - 2015-11-13 18:08:44,480 DEBUG : BROWSER_OUTPUT: RSS: Main: 299016192 18:08:44 INFO - 2015-11-13 18:08:44,480 DEBUG : BROWSER_OUTPUT: 18:08:45 INFO - 2015-11-13 18:08:45,248 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:45 INFO - 2015-11-13 18:08:45,841 DEBUG : BROWSER_OUTPUT: RSS: Main: 300904448 18:08:45 INFO - 2015-11-13 18:08:45,841 DEBUG : BROWSER_OUTPUT: 18:08:46 INFO - 2015-11-13 18:08:46,577 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:47 INFO - 2015-11-13 18:08:47,169 DEBUG : BROWSER_OUTPUT: RSS: Main: 300531712 18:08:47 INFO - 2015-11-13 18:08:47,169 DEBUG : BROWSER_OUTPUT: 18:08:47 INFO - 2015-11-13 18:08:47,941 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:48 INFO - 2015-11-13 18:08:48,529 DEBUG : BROWSER_OUTPUT: RSS: Main: 300298240 18:08:48 INFO - 2015-11-13 18:08:48,529 DEBUG : BROWSER_OUTPUT: 18:08:49 INFO - 2015-11-13 18:08:49,304 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:49 INFO - 2015-11-13 18:08:49,910 DEBUG : BROWSER_OUTPUT: RSS: Main: 301412352 18:08:49 INFO - 2015-11-13 18:08:49,910 DEBUG : BROWSER_OUTPUT: 18:08:50 INFO - 2015-11-13 18:08:50,676 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:51 INFO - 2015-11-13 18:08:51,262 DEBUG : BROWSER_OUTPUT: RSS: Main: 298819584 18:08:51 INFO - 2015-11-13 18:08:51,262 DEBUG : BROWSER_OUTPUT: 18:08:52 INFO - 2015-11-13 18:08:52,031 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:52 INFO - 2015-11-13 18:08:52,618 DEBUG : BROWSER_OUTPUT: RSS: Main: 301068288 18:08:52 INFO - 2015-11-13 18:08:52,619 DEBUG : BROWSER_OUTPUT: 18:08:53 INFO - 2015-11-13 18:08:53,390 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:53 INFO - 2015-11-13 18:08:53,979 DEBUG : BROWSER_OUTPUT: RSS: Main: 301035520 18:08:53 INFO - 2015-11-13 18:08:53,980 DEBUG : BROWSER_OUTPUT: 18:08:54 INFO - 2015-11-13 18:08:54,747 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:55 INFO - 2015-11-13 18:08:55,336 DEBUG : BROWSER_OUTPUT: RSS: Main: 301031424 18:08:55 INFO - 2015-11-13 18:08:55,336 DEBUG : BROWSER_OUTPUT: 18:08:56 INFO - 2015-11-13 18:08:56,113 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:56 INFO - 2015-11-13 18:08:56,703 DEBUG : BROWSER_OUTPUT: RSS: Main: 301215744 18:08:56 INFO - 2015-11-13 18:08:56,703 DEBUG : BROWSER_OUTPUT: 18:08:57 INFO - 2015-11-13 18:08:57,473 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:57 INFO - 2015-11-13 18:08:57,731 DEBUG : BROWSER_OUTPUT: RSS: Main: 302555136 18:08:57 INFO - 2015-11-13 18:08:57,731 DEBUG : BROWSER_OUTPUT: 18:08:57 INFO - 2015-11-13 18:08:57,731 DEBUG : BROWSER_OUTPUT: __start_tp_report 18:08:57 INFO - 2015-11-13 18:08:57,731 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load 18:08:57 INFO - 2015-11-13 18:08:57,732 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load_details 18:08:57 INFO - 2015-11-13 18:08:57,732 DEBUG : BROWSER_OUTPUT: |i|pagename|runs| 18:08:57 INFO - 2015-11-13 18:08:57,732 DEBUG : BROWSER_OUTPUT: |0;dhtml.html;1235;1272;1285;1286;1259;1277;1332;1275;1295;1286;1292;1203;1293;1286;1305;1190;1334;1331;1292;1201;1307;1294;1292;1293;1326 18:08:57 INFO - 2015-11-13 18:08:57,732 DEBUG : BROWSER_OUTPUT: |1;tablemutation.html;286;285;286;284;287;284;285;286;286;286;284;286;284;285;286;286;285;284;285;286;286;287;286;286;285 18:08:57 INFO - 2015-11-13 18:08:57,732 DEBUG : BROWSER_OUTPUT: __end_tp_report 18:08:57 INFO - 2015-11-13 18:08:57,732 DEBUG : BROWSER_OUTPUT: __start_cc_report 18:08:57 INFO - 2015-11-13 18:08:57,732 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_cycle_collect,6560 18:08:57 INFO - 2015-11-13 18:08:57,732 DEBUG : BROWSER_OUTPUT: __end_cc_report 18:08:57 INFO - 2015-11-13 18:08:57,733 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466937726__endTimestamp 18:08:57 INFO - 2015-11-13 18:08:57,733 DEBUG : BROWSER_OUTPUT: 18:08:57 INFO - 2015-11-13 18:08:57,733 DEBUG : BROWSER_OUTPUT: ------- Summary: start ------- 18:08:57 INFO - 2015-11-13 18:08:57,733 DEBUG : BROWSER_OUTPUT: Number of tests: 2 18:08:57 INFO - 2015-11-13 18:08:57,733 DEBUG : BROWSER_OUTPUT: 18:08:57 INFO - 2015-11-13 18:08:57,733 DEBUG : BROWSER_OUTPUT: [#0] dhtml.html Cycles:25 Average:1281.64 Median:1292.00 stddev:38.61 (3.0%) stddev-sans-first:38.17 18:08:57 INFO - 2015-11-13 18:08:57,733 DEBUG : BROWSER_OUTPUT: Values: 1235.0 1272.0 1285.0 1286.0 1259.0 1277.0 1332.0 1275.0 1295.0 1286.0 1292.0 1203.0 1293.0 1286.0 1305.0 1190.0 1334.0 1331.0 1292.0 1201.0 1307.0 1294.0 1292.0 1293.0 1326.0 18:08:57 INFO - 2015-11-13 18:08:57,733 DEBUG : BROWSER_OUTPUT: 18:08:57 INFO - 2015-11-13 18:08:57,734 DEBUG : BROWSER_OUTPUT: [#1] tablemutation.html Cycles:25 Average:285.44 Median:286.00 stddev:0.92 (0.3%) stddev-sans-first:0.93 18:08:57 INFO - 2015-11-13 18:08:57,734 DEBUG : BROWSER_OUTPUT: Values: 286.0 285.0 286.0 284.0 287.0 284.0 285.0 286.0 286.0 286.0 284.0 286.0 284.0 285.0 286.0 286.0 285.0 284.0 285.0 286.0 286.0 287.0 286.0 286.0 285.0 18:08:57 INFO - 2015-11-13 18:08:57,734 DEBUG : BROWSER_OUTPUT: -------- Summary: end -------- 18:08:57 INFO - 2015-11-13 18:08:57,734 DEBUG : BROWSER_OUTPUT: 18:08:58 INFO - 2015-11-13 18:08:58,270 INFO : Browser exited with error code: 0 18:08:58 INFO - 2015-11-13 18:08:58,296 INFO : Completed test a11yr (00:01:42) 18:08:58 INFO - 2015-11-13 18:08:58,296 INFO : Starting test ts_paint 18:08:58 INFO - 2015-11-13 18:08:58,296 DEBUG : operating with platform_type : mac_ 18:08:58 INFO - 2015-11-13 18:08:58,296 INFO : Initialising browser for ts_paint test... 18:08:58 INFO - 2015-11-13 18:08:58,312 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpUoow4r/profile http://localhost:49265/getInfo.html 18:09:00 INFO - 2015-11-13 18:09:00,833 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 18:09:00 INFO - 2015-11-13 18:09:00,833 DEBUG : BROWSER_OUTPUT: colorDepth:24 18:09:00 INFO - 2015-11-13 18:09:00,834 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/689 18:09:00 INFO - 2015-11-13 18:09:00,834 DEBUG : BROWSER_OUTPUT: __metrics 18:09:00 INFO - 2015-11-13 18:09:00,851 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 18:09:01 INFO - 2015-11-13 18:09:01,602 INFO : Browser initialized. 18:09:01 INFO - 2015-11-13 18:09:01,603 INFO : Running cycle 1/20 for ts_paint test... 18:09:01 INFO - 2015-11-13 18:09:01,603 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpUoow4r/profile http://localhost:49265/startup_test/tspaint_test.html 18:09:03 INFO - 2015-11-13 18:09:03,618 DEBUG : BROWSER_OUTPUT: __start_report2008__end_report 18:09:03 INFO - 2015-11-13 18:09:03,618 DEBUG : BROWSER_OUTPUT: 18:09:03 INFO - 2015-11-13 18:09:03,636 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466943626__endTimestamp 18:09:04 INFO - 2015-11-13 18:09:04,349 INFO : Browser exited with error code: 0 18:09:04 INFO - 2015-11-13 18:09:04,351 INFO : Running cycle 2/20 for ts_paint test... 18:09:04 INFO - 2015-11-13 18:09:04,351 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpUoow4r/profile http://localhost:49265/startup_test/tspaint_test.html 18:09:05 INFO - 2015-11-13 18:09:05,834 DEBUG : BROWSER_OUTPUT: __start_report1478__end_report 18:09:05 INFO - 2015-11-13 18:09:05,834 DEBUG : BROWSER_OUTPUT: 18:09:05 INFO - 2015-11-13 18:09:05,850 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466945843__endTimestamp 18:09:06 INFO - 2015-11-13 18:09:06,550 INFO : Browser exited with error code: 0 18:09:06 INFO - 2015-11-13 18:09:06,552 INFO : Running cycle 3/20 for ts_paint test... 18:09:06 INFO - 2015-11-13 18:09:06,552 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpUoow4r/profile http://localhost:49265/startup_test/tspaint_test.html 18:09:08 INFO - 2015-11-13 18:09:08,036 DEBUG : BROWSER_OUTPUT: __start_report1481__end_report 18:09:08 INFO - 2015-11-13 18:09:08,037 DEBUG : BROWSER_OUTPUT: 18:09:08 INFO - 2015-11-13 18:09:08,040 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466948039__endTimestamp 18:09:08 INFO - 2015-11-13 18:09:08,807 INFO : Browser exited with error code: 0 18:09:08 INFO - 2015-11-13 18:09:08,809 INFO : Running cycle 4/20 for ts_paint test... 18:09:08 INFO - 2015-11-13 18:09:08,809 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpUoow4r/profile http://localhost:49265/startup_test/tspaint_test.html 18:09:10 INFO - 2015-11-13 18:09:10,295 DEBUG : BROWSER_OUTPUT: __start_report1483__end_report 18:09:10 INFO - 2015-11-13 18:09:10,295 DEBUG : BROWSER_OUTPUT: 18:09:10 INFO - 2015-11-13 18:09:10,313 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466950308__endTimestamp 18:09:11 INFO - 2015-11-13 18:09:11,048 INFO : Browser exited with error code: 0 18:09:11 INFO - 2015-11-13 18:09:11,050 INFO : Running cycle 5/20 for ts_paint test... 18:09:11 INFO - 2015-11-13 18:09:11,050 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpUoow4r/profile http://localhost:49265/startup_test/tspaint_test.html 18:09:12 INFO - 2015-11-13 18:09:12,528 DEBUG : BROWSER_OUTPUT: __start_report1474__end_report 18:09:12 INFO - 2015-11-13 18:09:12,529 DEBUG : BROWSER_OUTPUT: 18:09:12 INFO - 2015-11-13 18:09:12,548 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466952540__endTimestamp 18:09:13 INFO - 2015-11-13 18:09:13,343 INFO : Browser exited with error code: 0 18:09:13 INFO - 2015-11-13 18:09:13,345 INFO : Running cycle 6/20 for ts_paint test... 18:09:13 INFO - 2015-11-13 18:09:13,345 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpUoow4r/profile http://localhost:49265/startup_test/tspaint_test.html 18:09:14 INFO - 2015-11-13 18:09:14,829 DEBUG : BROWSER_OUTPUT: __start_report1482__end_report 18:09:14 INFO - 2015-11-13 18:09:14,829 DEBUG : BROWSER_OUTPUT: 18:09:14 INFO - 2015-11-13 18:09:14,847 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466954843__endTimestamp 18:09:15 INFO - 2015-11-13 18:09:15,650 INFO : Browser exited with error code: 0 18:09:15 INFO - 2015-11-13 18:09:15,651 INFO : Running cycle 7/20 for ts_paint test... 18:09:15 INFO - 2015-11-13 18:09:15,651 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpUoow4r/profile http://localhost:49265/startup_test/tspaint_test.html 18:09:17 INFO - 2015-11-13 18:09:17,129 DEBUG : BROWSER_OUTPUT: __start_report1474__end_report 18:09:17 INFO - 2015-11-13 18:09:17,129 DEBUG : BROWSER_OUTPUT: 18:09:17 INFO - 2015-11-13 18:09:17,148 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466957142__endTimestamp 18:09:17 INFO - 2015-11-13 18:09:17,947 INFO : Browser exited with error code: 0 18:09:17 INFO - 2015-11-13 18:09:17,948 INFO : Running cycle 8/20 for ts_paint test... 18:09:17 INFO - 2015-11-13 18:09:17,948 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpUoow4r/profile http://localhost:49265/startup_test/tspaint_test.html 18:09:19 INFO - 2015-11-13 18:09:19,432 DEBUG : BROWSER_OUTPUT: __start_report1476__end_report 18:09:19 INFO - 2015-11-13 18:09:19,433 DEBUG : BROWSER_OUTPUT: 18:09:19 INFO - 2015-11-13 18:09:19,452 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466959441__endTimestamp 18:09:20 INFO - 2015-11-13 18:09:20,268 INFO : Browser exited with error code: 0 18:09:20 INFO - 2015-11-13 18:09:20,270 INFO : Running cycle 9/20 for ts_paint test... 18:09:20 INFO - 2015-11-13 18:09:20,270 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpUoow4r/profile http://localhost:49265/startup_test/tspaint_test.html 18:09:21 INFO - 2015-11-13 18:09:21,750 DEBUG : BROWSER_OUTPUT: __start_report1476__end_report 18:09:21 INFO - 2015-11-13 18:09:21,750 DEBUG : BROWSER_OUTPUT: 18:09:21 INFO - 2015-11-13 18:09:21,766 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466961759__endTimestamp 18:09:22 INFO - 2015-11-13 18:09:22,606 INFO : Browser exited with error code: 0 18:09:22 INFO - 2015-11-13 18:09:22,608 INFO : Running cycle 10/20 for ts_paint test... 18:09:22 INFO - 2015-11-13 18:09:22,608 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpUoow4r/profile http://localhost:49265/startup_test/tspaint_test.html 18:09:24 INFO - 2015-11-13 18:09:24,079 DEBUG : BROWSER_OUTPUT: __start_report1467__end_report 18:09:24 INFO - 2015-11-13 18:09:24,080 DEBUG : BROWSER_OUTPUT: 18:09:24 INFO - 2015-11-13 18:09:24,096 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466964092__endTimestamp 18:09:24 INFO - 2015-11-13 18:09:24,895 INFO : Browser exited with error code: 0 18:09:24 INFO - 2015-11-13 18:09:24,896 INFO : Running cycle 11/20 for ts_paint test... 18:09:24 INFO - 2015-11-13 18:09:24,897 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpUoow4r/profile http://localhost:49265/startup_test/tspaint_test.html 18:09:26 INFO - 2015-11-13 18:09:26,380 DEBUG : BROWSER_OUTPUT: __start_report1479__end_report 18:09:26 INFO - 2015-11-13 18:09:26,380 DEBUG : BROWSER_OUTPUT: 18:09:26 INFO - 2015-11-13 18:09:26,396 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466966392__endTimestamp 18:09:27 INFO - 2015-11-13 18:09:27,209 INFO : Browser exited with error code: 0 18:09:27 INFO - 2015-11-13 18:09:27,211 INFO : Running cycle 12/20 for ts_paint test... 18:09:27 INFO - 2015-11-13 18:09:27,211 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpUoow4r/profile http://localhost:49265/startup_test/tspaint_test.html 18:09:28 INFO - 2015-11-13 18:09:28,684 DEBUG : BROWSER_OUTPUT: __start_report1468__end_report 18:09:28 INFO - 2015-11-13 18:09:28,684 DEBUG : BROWSER_OUTPUT: 18:09:28 INFO - 2015-11-13 18:09:28,700 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466968692__endTimestamp 18:09:29 INFO - 2015-11-13 18:09:29,545 INFO : Browser exited with error code: 0 18:09:29 INFO - 2015-11-13 18:09:29,547 INFO : Running cycle 13/20 for ts_paint test... 18:09:29 INFO - 2015-11-13 18:09:29,547 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpUoow4r/profile http://localhost:49265/startup_test/tspaint_test.html 18:09:31 INFO - 2015-11-13 18:09:31,016 DEBUG : BROWSER_OUTPUT: __start_report1465__end_report 18:09:31 INFO - 2015-11-13 18:09:31,016 DEBUG : BROWSER_OUTPUT: 18:09:31 INFO - 2015-11-13 18:09:31,033 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466971025__endTimestamp 18:09:31 INFO - 2015-11-13 18:09:31,866 INFO : Browser exited with error code: 0 18:09:31 INFO - 2015-11-13 18:09:31,868 INFO : Running cycle 14/20 for ts_paint test... 18:09:31 INFO - 2015-11-13 18:09:31,868 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpUoow4r/profile http://localhost:49265/startup_test/tspaint_test.html 18:09:33 INFO - 2015-11-13 18:09:33,344 DEBUG : BROWSER_OUTPUT: __start_report1474__end_report 18:09:33 INFO - 2015-11-13 18:09:33,345 DEBUG : BROWSER_OUTPUT: 18:09:33 INFO - 2015-11-13 18:09:33,360 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466973359__endTimestamp 18:09:34 INFO - 2015-11-13 18:09:34,196 INFO : Browser exited with error code: 0 18:09:34 INFO - 2015-11-13 18:09:34,197 INFO : Running cycle 15/20 for ts_paint test... 18:09:34 INFO - 2015-11-13 18:09:34,197 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpUoow4r/profile http://localhost:49265/startup_test/tspaint_test.html 18:09:35 INFO - 2015-11-13 18:09:35,666 DEBUG : BROWSER_OUTPUT: __start_report1465__end_report 18:09:35 INFO - 2015-11-13 18:09:35,667 DEBUG : BROWSER_OUTPUT: 18:09:35 INFO - 2015-11-13 18:09:35,682 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466975676__endTimestamp 18:09:36 INFO - 2015-11-13 18:09:36,498 INFO : Browser exited with error code: 0 18:09:36 INFO - 2015-11-13 18:09:36,499 INFO : Running cycle 16/20 for ts_paint test... 18:09:36 INFO - 2015-11-13 18:09:36,499 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpUoow4r/profile http://localhost:49265/startup_test/tspaint_test.html 18:09:37 INFO - 2015-11-13 18:09:37,985 DEBUG : BROWSER_OUTPUT: __start_report1480__end_report 18:09:37 INFO - 2015-11-13 18:09:37,985 DEBUG : BROWSER_OUTPUT: 18:09:37 INFO - 2015-11-13 18:09:37,993 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466977992__endTimestamp 18:09:38 INFO - 2015-11-13 18:09:38,850 INFO : Browser exited with error code: 0 18:09:38 INFO - 2015-11-13 18:09:38,852 INFO : Running cycle 17/20 for ts_paint test... 18:09:38 INFO - 2015-11-13 18:09:38,852 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpUoow4r/profile http://localhost:49265/startup_test/tspaint_test.html 18:09:40 INFO - 2015-11-13 18:09:40,324 DEBUG : BROWSER_OUTPUT: __start_report1462__end_report 18:09:40 INFO - 2015-11-13 18:09:40,325 DEBUG : BROWSER_OUTPUT: 18:09:40 INFO - 2015-11-13 18:09:40,328 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466980328__endTimestamp 18:09:41 INFO - 2015-11-13 18:09:41,174 INFO : Browser exited with error code: 0 18:09:41 INFO - 2015-11-13 18:09:41,175 INFO : Running cycle 18/20 for ts_paint test... 18:09:41 INFO - 2015-11-13 18:09:41,175 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpUoow4r/profile http://localhost:49265/startup_test/tspaint_test.html 18:09:42 INFO - 2015-11-13 18:09:42,652 DEBUG : BROWSER_OUTPUT: __start_report1473__end_report 18:09:42 INFO - 2015-11-13 18:09:42,652 DEBUG : BROWSER_OUTPUT: 18:09:42 INFO - 2015-11-13 18:09:42,668 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466982662__endTimestamp 18:09:43 INFO - 2015-11-13 18:09:43,533 INFO : Browser exited with error code: 0 18:09:43 INFO - 2015-11-13 18:09:43,535 INFO : Running cycle 19/20 for ts_paint test... 18:09:43 INFO - 2015-11-13 18:09:43,535 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpUoow4r/profile http://localhost:49265/startup_test/tspaint_test.html 18:09:45 INFO - 2015-11-13 18:09:45,017 DEBUG : BROWSER_OUTPUT: __start_report1474__end_report 18:09:45 INFO - 2015-11-13 18:09:45,018 DEBUG : BROWSER_OUTPUT: 18:09:45 INFO - 2015-11-13 18:09:45,037 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466985026__endTimestamp 18:09:45 INFO - 2015-11-13 18:09:45,885 INFO : Browser exited with error code: 0 18:09:45 INFO - 2015-11-13 18:09:45,886 INFO : Running cycle 20/20 for ts_paint test... 18:09:45 INFO - 2015-11-13 18:09:45,886 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpUoow4r/profile http://localhost:49265/startup_test/tspaint_test.html 18:09:47 INFO - 2015-11-13 18:09:47,370 DEBUG : BROWSER_OUTPUT: __start_report1477__end_report 18:09:47 INFO - 2015-11-13 18:09:47,370 DEBUG : BROWSER_OUTPUT: 18:09:47 INFO - 2015-11-13 18:09:47,378 DEBUG : BROWSER_OUTPUT: __startTimestamp1447466987376__endTimestamp 18:09:48 INFO - 2015-11-13 18:09:48,218 INFO : Browser exited with error code: 0 18:09:48 INFO - 2015-11-13 18:09:48,248 INFO : Completed test ts_paint (00:00:49) 18:09:48 INFO - 2015-11-13 18:09:48,248 INFO : Starting test tpaint 18:09:48 INFO - 2015-11-13 18:09:48,248 DEBUG : operating with platform_type : mac_ 18:09:48 INFO - 2015-11-13 18:09:48,249 INFO : Initialising browser for tpaint test... 18:09:48 INFO - 2015-11-13 18:09:48,266 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpZNLz1x/profile http://localhost:49265/getInfo.html 18:09:50 INFO - 2015-11-13 18:09:50,679 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 18:09:50 INFO - 2015-11-13 18:09:50,679 DEBUG : BROWSER_OUTPUT: colorDepth:24 18:09:50 INFO - 2015-11-13 18:09:50,679 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/689 18:09:50 INFO - 2015-11-13 18:09:50,680 DEBUG : BROWSER_OUTPUT: __metrics 18:09:50 INFO - 2015-11-13 18:09:50,699 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 18:09:51 INFO - 2015-11-13 18:09:51,499 INFO : Browser initialized. 18:09:51 INFO - 2015-11-13 18:09:51,500 INFO : Running cycle 1/1 for tpaint test... 18:09:51 INFO - 2015-11-13 18:09:51,500 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpZNLz1x/profile file:///builds/slave/test/build/tests/talos/talos/startup_test/tpaint.html?auto=1 18:10:20 INFO - 2015-11-13 18:10:20,893 DEBUG : BROWSER_OUTPUT: __start_report331.5149999999994|332.09000000000015|333.6099999999997|335.38499999999976|339.6750000000002|344.6299999999992|347.09000000000015|354.7750000000001|357.66999999999825|362.64000000000124|362.8349999999991|365.6000000000022|365.8500000000022|370.8199999999997|379.85499999999956|390.21000000000276|405.9800000000014|409.3199999999997|415.4200000000019|487.09000000000015__end_report__startTimestamp1447467020890__endTimestamp 18:10:20 INFO - 2015-11-13 18:10:20,893 DEBUG : BROWSER_OUTPUT: openingTimes=332.09000000000015,333.6099999999997,335.38499999999976,339.6750000000002,344.6299999999992,347.09000000000015,354.7750000000001,357.66999999999825,362.64000000000124,362.8349999999991,365.6000000000022,365.8500000000022,370.8199999999997,379.85499999999956,390.21000000000276,405.9800000000014,409.3199999999997,415.4200000000019,487.09000000000015 18:10:20 INFO - 2015-11-13 18:10:20,893 DEBUG : BROWSER_OUTPUT: avgOpenTime:369.60 18:10:20 INFO - 2015-11-13 18:10:20,893 DEBUG : BROWSER_OUTPUT: minOpenTime:331.51 18:10:20 INFO - 2015-11-13 18:10:20,893 DEBUG : BROWSER_OUTPUT: maxOpenTime:487.09 18:10:20 INFO - 2015-11-13 18:10:20,893 DEBUG : BROWSER_OUTPUT: medOpenTime:362.7375000000002 18:10:20 INFO - 2015-11-13 18:10:20,893 DEBUG : BROWSER_OUTPUT: __xulWinOpenTime:362.7375000000002 18:10:21 INFO - 2015-11-13 18:10:21,742 INFO : Browser exited with error code: 0 18:10:21 INFO - 2015-11-13 18:10:21,764 INFO : Completed test tpaint (00:00:33) 18:10:21 INFO - 2015-11-13 18:10:21,764 INFO : Starting test sessionrestore 18:10:21 INFO - 2015-11-13 18:10:21,764 DEBUG : operating with platform_type : mac_ 18:10:21 INFO - 2015-11-13 18:10:21,764 INFO : Initialising browser for sessionrestore test... 18:10:21 INFO - 2015-11-13 18:10:21,788 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile http://localhost:49265/getInfo.html 18:10:27 INFO - 2015-11-13 18:10:27,948 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 18:10:27 INFO - 2015-11-13 18:10:27,949 DEBUG : BROWSER_OUTPUT: colorDepth:24 18:10:27 INFO - 2015-11-13 18:10:27,949 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1200/743 18:10:27 INFO - 2015-11-13 18:10:27,949 DEBUG : BROWSER_OUTPUT: __metrics 18:10:28 INFO - 2015-11-13 18:10:28,050 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 18:10:29 INFO - 2015-11-13 18:10:29,451 INFO : Browser initialized. 18:10:29 INFO - 2015-11-13 18:10:29,452 INFO : Running cycle 1/10 for sessionrestore test... 18:10:29 INFO - 2015-11-13 18:10:29,452 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile/sessionstore.js 18:10:29 INFO - 2015-11-13 18:10:29,455 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile/sessionCheckpoints.json 18:10:29 INFO - 2015-11-13 18:10:29,455 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile http://localhost:49265/startup_test/sessionrestore/index.html 18:10:35 INFO - 2015-11-13 18:10:35,218 DEBUG : BROWSER_OUTPUT: __start_report3036__end_report 18:10:35 INFO - 2015-11-13 18:10:35,218 DEBUG : BROWSER_OUTPUT: 18:10:35 INFO - 2015-11-13 18:10:35,218 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467035212__endTimestamp 18:10:35 INFO - 2015-11-13 18:10:35,218 DEBUG : BROWSER_OUTPUT: 18:10:36 INFO - 2015-11-13 18:10:36,670 INFO : Browser exited with error code: 0 18:10:36 INFO - 2015-11-13 18:10:36,672 INFO : Running cycle 2/10 for sessionrestore test... 18:10:36 INFO - 2015-11-13 18:10:36,672 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile/sessionstore.js 18:10:36 INFO - 2015-11-13 18:10:36,674 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile/sessionCheckpoints.json 18:10:36 INFO - 2015-11-13 18:10:36,675 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile http://localhost:49265/startup_test/sessionrestore/index.html 18:10:41 INFO - 2015-11-13 18:10:41,750 DEBUG : BROWSER_OUTPUT: __start_report2684__end_report 18:10:41 INFO - 2015-11-13 18:10:41,750 DEBUG : BROWSER_OUTPUT: 18:10:41 INFO - 2015-11-13 18:10:41,750 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467041749__endTimestamp 18:10:41 INFO - 2015-11-13 18:10:41,750 DEBUG : BROWSER_OUTPUT: 18:10:43 INFO - 2015-11-13 18:10:43,228 INFO : Browser exited with error code: 0 18:10:43 INFO - 2015-11-13 18:10:43,230 INFO : Running cycle 3/10 for sessionrestore test... 18:10:43 INFO - 2015-11-13 18:10:43,230 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile/sessionstore.js 18:10:43 INFO - 2015-11-13 18:10:43,232 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile/sessionCheckpoints.json 18:10:43 INFO - 2015-11-13 18:10:43,232 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile http://localhost:49265/startup_test/sessionrestore/index.html 18:10:48 INFO - 2015-11-13 18:10:48,305 DEBUG : BROWSER_OUTPUT: __start_report2679__end_report 18:10:48 INFO - 2015-11-13 18:10:48,305 DEBUG : BROWSER_OUTPUT: 18:10:48 INFO - 2015-11-13 18:10:48,305 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467048304__endTimestamp 18:10:48 INFO - 2015-11-13 18:10:48,305 DEBUG : BROWSER_OUTPUT: 18:10:49 INFO - 2015-11-13 18:10:49,818 INFO : Browser exited with error code: 0 18:10:49 INFO - 2015-11-13 18:10:49,820 INFO : Running cycle 4/10 for sessionrestore test... 18:10:49 INFO - 2015-11-13 18:10:49,820 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile/sessionstore.js 18:10:49 INFO - 2015-11-13 18:10:49,823 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile/sessionCheckpoints.json 18:10:49 INFO - 2015-11-13 18:10:49,823 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile http://localhost:49265/startup_test/sessionrestore/index.html 18:10:54 INFO - 2015-11-13 18:10:54,886 DEBUG : BROWSER_OUTPUT: __start_report2668__end_report 18:10:54 INFO - 2015-11-13 18:10:54,886 DEBUG : BROWSER_OUTPUT: 18:10:54 INFO - 2015-11-13 18:10:54,886 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467054884__endTimestamp 18:10:54 INFO - 2015-11-13 18:10:54,886 DEBUG : BROWSER_OUTPUT: 18:10:56 INFO - 2015-11-13 18:10:56,452 INFO : Browser exited with error code: 0 18:10:56 INFO - 2015-11-13 18:10:56,454 INFO : Running cycle 5/10 for sessionrestore test... 18:10:56 INFO - 2015-11-13 18:10:56,454 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile/sessionstore.js 18:10:56 INFO - 2015-11-13 18:10:56,459 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile/sessionCheckpoints.json 18:10:56 INFO - 2015-11-13 18:10:56,460 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile http://localhost:49265/startup_test/sessionrestore/index.html 18:11:01 INFO - 2015-11-13 18:11:01,525 DEBUG : BROWSER_OUTPUT: __start_report2667__end_report 18:11:01 INFO - 2015-11-13 18:11:01,525 DEBUG : BROWSER_OUTPUT: 18:11:01 INFO - 2015-11-13 18:11:01,525 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467061522__endTimestamp 18:11:01 INFO - 2015-11-13 18:11:01,525 DEBUG : BROWSER_OUTPUT: 18:11:03 INFO - 2015-11-13 18:11:03,136 INFO : Browser exited with error code: 0 18:11:03 INFO - 2015-11-13 18:11:03,138 INFO : Running cycle 6/10 for sessionrestore test... 18:11:03 INFO - 2015-11-13 18:11:03,138 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile/sessionstore.js 18:11:03 INFO - 2015-11-13 18:11:03,143 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile/sessionCheckpoints.json 18:11:03 INFO - 2015-11-13 18:11:03,143 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile http://localhost:49265/startup_test/sessionrestore/index.html 18:11:08 INFO - 2015-11-13 18:11:08,199 DEBUG : BROWSER_OUTPUT: __start_report2664__end_report 18:11:08 INFO - 2015-11-13 18:11:08,199 DEBUG : BROWSER_OUTPUT: 18:11:08 INFO - 2015-11-13 18:11:08,199 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467068198__endTimestamp 18:11:08 INFO - 2015-11-13 18:11:08,199 DEBUG : BROWSER_OUTPUT: 18:11:09 INFO - 2015-11-13 18:11:09,768 INFO : Browser exited with error code: 0 18:11:09 INFO - 2015-11-13 18:11:09,770 INFO : Running cycle 7/10 for sessionrestore test... 18:11:09 INFO - 2015-11-13 18:11:09,770 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile/sessionstore.js 18:11:09 INFO - 2015-11-13 18:11:09,794 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile/sessionCheckpoints.json 18:11:09 INFO - 2015-11-13 18:11:09,795 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile http://localhost:49265/startup_test/sessionrestore/index.html 18:11:14 INFO - 2015-11-13 18:11:14,869 DEBUG : BROWSER_OUTPUT: __start_report2673__end_report 18:11:14 INFO - 2015-11-13 18:11:14,869 DEBUG : BROWSER_OUTPUT: 18:11:14 INFO - 2015-11-13 18:11:14,869 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467074867__endTimestamp 18:11:14 INFO - 2015-11-13 18:11:14,869 DEBUG : BROWSER_OUTPUT: 18:11:16 INFO - 2015-11-13 18:11:16,457 INFO : Browser exited with error code: 0 18:11:16 INFO - 2015-11-13 18:11:16,459 INFO : Running cycle 8/10 for sessionrestore test... 18:11:16 INFO - 2015-11-13 18:11:16,459 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile/sessionstore.js 18:11:16 INFO - 2015-11-13 18:11:16,464 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile/sessionCheckpoints.json 18:11:16 INFO - 2015-11-13 18:11:16,464 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile http://localhost:49265/startup_test/sessionrestore/index.html 18:11:21 INFO - 2015-11-13 18:11:21,544 DEBUG : BROWSER_OUTPUT: __start_report2660__end_report 18:11:21 INFO - 2015-11-13 18:11:21,545 DEBUG : BROWSER_OUTPUT: 18:11:21 INFO - 2015-11-13 18:11:21,545 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467081540__endTimestamp 18:11:21 INFO - 2015-11-13 18:11:21,545 DEBUG : BROWSER_OUTPUT: 18:11:23 INFO - 2015-11-13 18:11:23,176 INFO : Browser exited with error code: 0 18:11:23 INFO - 2015-11-13 18:11:23,178 INFO : Running cycle 9/10 for sessionrestore test... 18:11:23 INFO - 2015-11-13 18:11:23,178 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile/sessionstore.js 18:11:23 INFO - 2015-11-13 18:11:23,183 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile/sessionCheckpoints.json 18:11:23 INFO - 2015-11-13 18:11:23,183 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile http://localhost:49265/startup_test/sessionrestore/index.html 18:11:28 INFO - 2015-11-13 18:11:28,261 DEBUG : BROWSER_OUTPUT: __start_report2679__end_report 18:11:28 INFO - 2015-11-13 18:11:28,261 DEBUG : BROWSER_OUTPUT: 18:11:28 INFO - 2015-11-13 18:11:28,261 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467088259__endTimestamp 18:11:28 INFO - 2015-11-13 18:11:28,262 DEBUG : BROWSER_OUTPUT: 18:11:29 INFO - 2015-11-13 18:11:29,870 INFO : Browser exited with error code: 0 18:11:29 INFO - 2015-11-13 18:11:29,871 INFO : Running cycle 10/10 for sessionrestore test... 18:11:29 INFO - 2015-11-13 18:11:29,872 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile/sessionstore.js 18:11:29 INFO - 2015-11-13 18:11:29,876 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile/sessionCheckpoints.json 18:11:29 INFO - 2015-11-13 18:11:29,877 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpKzVdg7/profile http://localhost:49265/startup_test/sessionrestore/index.html 18:11:34 INFO - 2015-11-13 18:11:34,965 DEBUG : BROWSER_OUTPUT: __start_report2688__end_report 18:11:34 INFO - 2015-11-13 18:11:34,966 DEBUG : BROWSER_OUTPUT: 18:11:34 INFO - 2015-11-13 18:11:34,966 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467094964__endTimestamp 18:11:34 INFO - 2015-11-13 18:11:34,966 DEBUG : BROWSER_OUTPUT: 18:11:36 INFO - 2015-11-13 18:11:36,597 INFO : Browser exited with error code: 0 18:11:36 INFO - 2015-11-13 18:11:36,625 INFO : Completed test sessionrestore (00:01:14) 18:11:36 INFO - 2015-11-13 18:11:36,625 INFO : Starting test sessionrestore_no_auto_restore 18:11:36 INFO - 2015-11-13 18:11:36,625 DEBUG : operating with platform_type : mac_ 18:11:36 INFO - 2015-11-13 18:11:36,625 INFO : Initialising browser for sessionrestore_no_auto_restore test... 18:11:36 INFO - 2015-11-13 18:11:36,648 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile http://localhost:49265/getInfo.html 18:11:39 INFO - 2015-11-13 18:11:39,139 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 18:11:39 INFO - 2015-11-13 18:11:39,139 DEBUG : BROWSER_OUTPUT: colorDepth:24 18:11:39 INFO - 2015-11-13 18:11:39,139 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1200/743 18:11:39 INFO - 2015-11-13 18:11:39,140 DEBUG : BROWSER_OUTPUT: __metrics 18:11:39 INFO - 2015-11-13 18:11:39,156 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 18:11:40 INFO - 2015-11-13 18:11:40,001 INFO : Browser initialized. 18:11:40 INFO - 2015-11-13 18:11:40,002 INFO : Running cycle 1/10 for sessionrestore_no_auto_restore test... 18:11:40 INFO - 2015-11-13 18:11:40,002 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile/sessionstore.js 18:11:40 INFO - 2015-11-13 18:11:40,007 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile/sessionCheckpoints.json 18:11:40 INFO - 2015-11-13 18:11:40,007 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile http://localhost:49265/startup_test/sessionrestore/index.html 18:11:42 INFO - 2015-11-13 18:11:42,156 DEBUG : BROWSER_OUTPUT: __start_report1465__end_report 18:11:42 INFO - 2015-11-13 18:11:42,156 DEBUG : BROWSER_OUTPUT: 18:11:42 INFO - 2015-11-13 18:11:42,156 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467102150__endTimestamp 18:11:42 INFO - 2015-11-13 18:11:42,156 DEBUG : BROWSER_OUTPUT: 18:11:42 INFO - 2015-11-13 18:11:42,997 INFO : Browser exited with error code: 0 18:11:42 INFO - 2015-11-13 18:11:42,999 INFO : Running cycle 2/10 for sessionrestore_no_auto_restore test... 18:11:42 INFO - 2015-11-13 18:11:42,999 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile/sessionstore.js 18:11:43 INFO - 2015-11-13 18:11:43,004 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile/sessionCheckpoints.json 18:11:43 INFO - 2015-11-13 18:11:43,005 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile http://localhost:49265/startup_test/sessionrestore/index.html 18:11:44 INFO - 2015-11-13 18:11:44,642 DEBUG : BROWSER_OUTPUT: __start_report1104__end_report 18:11:44 INFO - 2015-11-13 18:11:44,642 DEBUG : BROWSER_OUTPUT: 18:11:44 INFO - 2015-11-13 18:11:44,642 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467104632__endTimestamp 18:11:44 INFO - 2015-11-13 18:11:44,642 DEBUG : BROWSER_OUTPUT: 18:11:45 INFO - 2015-11-13 18:11:45,501 INFO : Browser exited with error code: 0 18:11:45 INFO - 2015-11-13 18:11:45,502 INFO : Running cycle 3/10 for sessionrestore_no_auto_restore test... 18:11:45 INFO - 2015-11-13 18:11:45,503 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile/sessionstore.js 18:11:45 INFO - 2015-11-13 18:11:45,508 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile/sessionCheckpoints.json 18:11:45 INFO - 2015-11-13 18:11:45,508 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile http://localhost:49265/startup_test/sessionrestore/index.html 18:11:47 INFO - 2015-11-13 18:11:47,183 DEBUG : BROWSER_OUTPUT: __start_report1120__end_report 18:11:47 INFO - 2015-11-13 18:11:47,184 DEBUG : BROWSER_OUTPUT: 18:11:47 INFO - 2015-11-13 18:11:47,184 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467107177__endTimestamp 18:11:47 INFO - 2015-11-13 18:11:47,184 DEBUG : BROWSER_OUTPUT: 18:11:47 INFO - 2015-11-13 18:11:47,966 INFO : Browser exited with error code: 0 18:11:47 INFO - 2015-11-13 18:11:47,968 INFO : Running cycle 4/10 for sessionrestore_no_auto_restore test... 18:11:47 INFO - 2015-11-13 18:11:47,968 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile/sessionstore.js 18:11:47 INFO - 2015-11-13 18:11:47,976 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile/sessionCheckpoints.json 18:11:47 INFO - 2015-11-13 18:11:47,976 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile http://localhost:49265/startup_test/sessionrestore/index.html 18:11:49 INFO - 2015-11-13 18:11:49,690 DEBUG : BROWSER_OUTPUT: __start_report1119__end_report 18:11:49 INFO - 2015-11-13 18:11:49,690 DEBUG : BROWSER_OUTPUT: 18:11:49 INFO - 2015-11-13 18:11:49,690 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467109688__endTimestamp 18:11:49 INFO - 2015-11-13 18:11:49,691 DEBUG : BROWSER_OUTPUT: 18:11:50 INFO - 2015-11-13 18:11:50,527 INFO : Browser exited with error code: 0 18:11:50 INFO - 2015-11-13 18:11:50,528 INFO : Running cycle 5/10 for sessionrestore_no_auto_restore test... 18:11:50 INFO - 2015-11-13 18:11:50,528 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile/sessionstore.js 18:11:50 INFO - 2015-11-13 18:11:50,533 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile/sessionCheckpoints.json 18:11:50 INFO - 2015-11-13 18:11:50,534 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile http://localhost:49265/startup_test/sessionrestore/index.html 18:11:52 INFO - 2015-11-13 18:11:52,169 DEBUG : BROWSER_OUTPUT: __start_report1107__end_report 18:11:52 INFO - 2015-11-13 18:11:52,169 DEBUG : BROWSER_OUTPUT: 18:11:52 INFO - 2015-11-13 18:11:52,169 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467112164__endTimestamp 18:11:52 INFO - 2015-11-13 18:11:52,169 DEBUG : BROWSER_OUTPUT: 18:11:53 INFO - 2015-11-13 18:11:53,082 INFO : Browser exited with error code: 0 18:11:53 INFO - 2015-11-13 18:11:53,083 INFO : Running cycle 6/10 for sessionrestore_no_auto_restore test... 18:11:53 INFO - 2015-11-13 18:11:53,083 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile/sessionstore.js 18:11:53 INFO - 2015-11-13 18:11:53,088 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile/sessionCheckpoints.json 18:11:53 INFO - 2015-11-13 18:11:53,089 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile http://localhost:49265/startup_test/sessionrestore/index.html 18:11:54 INFO - 2015-11-13 18:11:54,762 DEBUG : BROWSER_OUTPUT: __start_report1120__end_report 18:11:54 INFO - 2015-11-13 18:11:54,762 DEBUG : BROWSER_OUTPUT: 18:11:54 INFO - 2015-11-13 18:11:54,762 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467114758__endTimestamp 18:11:54 INFO - 2015-11-13 18:11:54,762 DEBUG : BROWSER_OUTPUT: 18:11:55 INFO - 2015-11-13 18:11:55,685 INFO : Browser exited with error code: 0 18:11:55 INFO - 2015-11-13 18:11:55,686 INFO : Running cycle 7/10 for sessionrestore_no_auto_restore test... 18:11:55 INFO - 2015-11-13 18:11:55,686 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile/sessionstore.js 18:11:55 INFO - 2015-11-13 18:11:55,692 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile/sessionCheckpoints.json 18:11:55 INFO - 2015-11-13 18:11:55,692 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile http://localhost:49265/startup_test/sessionrestore/index.html 18:11:57 INFO - 2015-11-13 18:11:57,358 DEBUG : BROWSER_OUTPUT: __start_report1117__end_report 18:11:57 INFO - 2015-11-13 18:11:57,358 DEBUG : BROWSER_OUTPUT: 18:11:57 INFO - 2015-11-13 18:11:57,358 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467117357__endTimestamp 18:11:57 INFO - 2015-11-13 18:11:57,359 DEBUG : BROWSER_OUTPUT: 18:11:58 INFO - 2015-11-13 18:11:58,260 INFO : Browser exited with error code: 0 18:11:58 INFO - 2015-11-13 18:11:58,262 INFO : Running cycle 8/10 for sessionrestore_no_auto_restore test... 18:11:58 INFO - 2015-11-13 18:11:58,262 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile/sessionstore.js 18:11:58 INFO - 2015-11-13 18:11:58,267 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile/sessionCheckpoints.json 18:11:58 INFO - 2015-11-13 18:11:58,267 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile http://localhost:49265/startup_test/sessionrestore/index.html 18:11:59 INFO - 2015-11-13 18:11:59,899 DEBUG : BROWSER_OUTPUT: __start_report1109__end_report 18:11:59 INFO - 2015-11-13 18:11:59,899 DEBUG : BROWSER_OUTPUT: 18:11:59 INFO - 2015-11-13 18:11:59,899 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467119898__endTimestamp 18:11:59 INFO - 2015-11-13 18:11:59,899 DEBUG : BROWSER_OUTPUT: 18:12:00 INFO - 2015-11-13 18:12:00,841 INFO : Browser exited with error code: 0 18:12:00 INFO - 2015-11-13 18:12:00,843 INFO : Running cycle 9/10 for sessionrestore_no_auto_restore test... 18:12:00 INFO - 2015-11-13 18:12:00,843 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile/sessionstore.js 18:12:00 INFO - 2015-11-13 18:12:00,848 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile/sessionCheckpoints.json 18:12:00 INFO - 2015-11-13 18:12:00,849 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile http://localhost:49265/startup_test/sessionrestore/index.html 18:12:02 INFO - 2015-11-13 18:12:02,505 DEBUG : BROWSER_OUTPUT: __start_report1103__end_report 18:12:02 INFO - 2015-11-13 18:12:02,505 DEBUG : BROWSER_OUTPUT: 18:12:02 INFO - 2015-11-13 18:12:02,505 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467122500__endTimestamp 18:12:02 INFO - 2015-11-13 18:12:02,505 DEBUG : BROWSER_OUTPUT: 18:12:03 INFO - 2015-11-13 18:12:03,418 INFO : Browser exited with error code: 0 18:12:03 INFO - 2015-11-13 18:12:03,420 INFO : Running cycle 10/10 for sessionrestore_no_auto_restore test... 18:12:03 INFO - 2015-11-13 18:12:03,420 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile/sessionstore.js 18:12:03 INFO - 2015-11-13 18:12:03,425 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile/sessionCheckpoints.json 18:12:03 INFO - 2015-11-13 18:12:03,426 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/T/tmpHTuHAG/profile http://localhost:49265/startup_test/sessionrestore/index.html 18:12:05 INFO - 2015-11-13 18:12:05,097 DEBUG : BROWSER_OUTPUT: __start_report1118__end_report 18:12:05 INFO - 2015-11-13 18:12:05,097 DEBUG : BROWSER_OUTPUT: 18:12:05 INFO - 2015-11-13 18:12:05,097 DEBUG : BROWSER_OUTPUT: __startTimestamp1447467125091__endTimestamp 18:12:05 INFO - 2015-11-13 18:12:05,098 DEBUG : BROWSER_OUTPUT: 18:12:06 INFO - 2015-11-13 18:12:06,001 INFO : Browser exited with error code: 0 18:12:06 INFO - 2015-11-13 18:12:06,027 INFO : Completed test sessionrestore_no_auto_restore (00:00:29) 18:12:06 INFO - 2015-11-13 18:12:06,465 INFO : Completed test suite (00:04:50) 18:12:06 INFO - 2015-11-13 18:12:06,465 DEBUG : Working with test: a11yr 18:12:06 INFO - 2015-11-13 18:12:06,465 DEBUG : Generating results file: a11yr 18:12:06 INFO - 2015-11-13 18:12:06,465 DEBUG : Working with test: ts_paint 18:12:06 INFO - 2015-11-13 18:12:06,466 DEBUG : Generating results file: ts_paint 18:12:06 INFO - 2015-11-13 18:12:06,466 DEBUG : Working with test: tpaint 18:12:06 INFO - 2015-11-13 18:12:06,466 DEBUG : Generating results file: tpaint 18:12:06 INFO - 2015-11-13 18:12:06,467 DEBUG : Working with test: sessionrestore 18:12:06 INFO - 2015-11-13 18:12:06,467 DEBUG : Generating results file: sessionrestore 18:12:06 INFO - 2015-11-13 18:12:06,467 DEBUG : Working with test: sessionrestore_no_auto_restore 18:12:06 INFO - 2015-11-13 18:12:06,467 DEBUG : Generating results file: sessionrestore_no_auto_restore 18:12:06 INFO - 2015-11-13 18:12:06,467 INFO : Posting result 0 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 18:12:06 INFO - 2015-11-13 18:12:06,521 DEBUG : process_Request line: a11yr_paint graph.html#tests=[[223,64,55]] 18:12:06 INFO - 2015-11-13 18:12:06,521 DEBUG : process_Request line: a11yr_paint 608.17 graph.html#tests=[[223,64,55]] 18:12:06 INFO - 2015-11-13 18:12:06,521 INFO : Posting result 1 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 18:12:06 INFO - 2015-11-13 18:12:06,582 DEBUG : process_Request line: ts_paint graph.html#tests=[[83,64,55]] 18:12:06 INFO - 2015-11-13 18:12:06,582 DEBUG : process_Request line: ts_paint 1497.05 graph.html#tests=[[83,64,55]] 18:12:06 INFO - 2015-11-13 18:12:06,582 INFO : Posting result 2 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 18:12:06 INFO - 2015-11-13 18:12:06,615 DEBUG : process_Request line: tpaint graph.html#tests=[[82,64,55]] 18:12:06 INFO - 2015-11-13 18:12:06,615 DEBUG : process_Request line: tpaint 365.85 graph.html#tests=[[82,64,55]] 18:12:06 INFO - 2015-11-13 18:12:06,615 INFO : Posting result 3 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 18:12:06 INFO - 2015-11-13 18:12:06,673 DEBUG : process_Request line: sessionrestore graph.html#tests=[[313,64,55]] 18:12:06 INFO - 2015-11-13 18:12:06,673 DEBUG : process_Request line: sessionrestore 2707.75 graph.html#tests=[[313,64,55]] 18:12:06 INFO - 2015-11-13 18:12:06,673 INFO : Posting result 4 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 18:12:06 INFO - 2015-11-13 18:12:06,722 DEBUG : process_Request line: sessionrestore_no_auto_restore graph.html#tests=[[315,64,55]] 18:12:06 INFO - 2015-11-13 18:12:06,723 DEBUG : process_Request line: sessionrestore_no_auto_restore 1143.99 graph.html#tests=[[315,64,55]] 18:12:06 INFO - 2015-11-13 18:12:06,723 INFO : TALOSDATA: [{"talos_counters": {}, "results": {"dhtml.html": [1235.0, 1272.0, 1285.0, 1286.0, 1259.0, 1277.0, 1332.0, 1275.0, 1295.0, 1286.0, 1292.0, 1203.0, 1293.0, 1286.0, 1305.0, 1190.0, 1334.0, 1331.0, 1292.0, 1201.0, 1307.0, 1294.0, 1292.0, 1293.0, 1326.0], "tablemutation.html": [286.0, 285.0, 286.0, 284.0, 287.0, 284.0, 285.0, 286.0, 286.0, 286.0, 284.0, 286.0, 284.0, 285.0, 286.0, 286.0, 285.0, 284.0, 285.0, 286.0, 286.0, 287.0, 286.0, 286.0, 285.0]}, "summary": {"lowerIsBetter": true, "suite": 608.1723893940037, "subtests": {"dhtml.html": {"lowerIsBetter": true, "filtered": 1292.0, "unit": "ms", "value": 1292.0}, "tablemutation.html": {"lowerIsBetter": true, "filtered": 286.0, "unit": "ms", "value": 286.0}}}, "test_machine": {"platform": "x86_64", "osversion": "OS X 10.10.2", "os": "mac", "name": "t-yosemite-r5-0104"}, "testrun": {"date": 1447466835, "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": [2008.0, 1478.0, 1481.0, 1483.0, 1474.0, 1482.0, 1474.0, 1476.0, 1476.0, 1467.0, 1479.0, 1468.0, 1465.0, 1474.0, 1465.0, 1480.0, 1462.0, 1473.0, 1474.0, 1477.0]}, "summary": {"suite": 1474.0, "subtests": {"ts_paint": {"filtered": 1474.0, "value": 1474.0}}}, "test_machine": {"platform": "x86_64", "osversion": "OS X 10.10.2", "os": "mac", "name": "t-yosemite-r5-0104"}, "testrun": {"date": 1447466835, "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": [331.5149999999994, 332.09000000000015, 333.6099999999997, 335.38499999999976, 339.6750000000002, 344.6299999999992, 347.09000000000015, 354.7750000000001, 357.66999999999825, 362.64000000000124, 362.8349999999991, 365.6000000000022, 365.8500000000022, 370.8199999999997, 379.85499999999956, 390.21000000000276, 405.9800000000014, 409.3199999999997, 415.4200000000019, 487.09000000000015]}, "summary": {"suite": 365.8500000000022, "subtests": {"tpaint": {"filtered": 365.8500000000022, "value": 365.8500000000022}}}, "test_machine": {"platform": "x86_64", "osversion": "OS X 10.10.2", "os": "mac", "name": "t-yosemite-r5-0104"}, "testrun": {"date": 1447466835, "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": [3036.0, 2684.0, 2679.0, 2668.0, 2667.0, 2664.0, 2673.0, 2660.0, 2679.0, 2688.0]}, "summary": {"suite": 2673.0, "subtests": {"sessionrestore": {"filtered": 2673.0, "value": 2673.0}}}, "test_machine": {"platform": "x86_64", "osversion": "OS X 10.10.2", "os": "mac", "name": "t-yosemite-r5-0104"}, "testrun": {"date": 1447466835, "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": [1465.0, 1104.0, 1120.0, 1119.0, 1107.0, 1120.0, 1117.0, 1109.0, 1103.0, 1118.0]}, "summary": {"suite": 1117.0, "subtests": {"sessionrestore_no_auto_restore": {"filtered": 1117.0, "value": 1117.0}}}, "test_machine": {"platform": "x86_64", "osversion": "OS X 10.10.2", "os": "mac", "name": "t-yosemite-r5-0104"}, "testrun": {"date": 1447466835, "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:12:06 INFO - RETURN: a11yr_paint: 608.17 18:12:06 INFO - RETURN: ts_paint: 1497.05 18:12:06 INFO - RETURN: tpaint: 365.85 18:12:06 INFO - RETURN: sessionrestore: 2707.75 18:12:06 INFO - RETURN: sessionrestore_no_auto_restore: 1143.99 18:12:06 INFO - TinderboxPrint: TalosResult: {"graphserver": {"sessionrestore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[313,64,55]]", "result": "2707.75"}, "a11yr_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[223,64,55]]", "result": "608.17"}, "tpaint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[82,64,55]]", "result": "365.85"}, "ts_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[83,64,55]]", "result": "1497.05"}, "sessionrestore_no_auto_restore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[315,64,55]]", "result": "1143.99"}}} 18:12:06 INFO - Return code: 0 18:12:06 INFO - # TBPL SUCCESS # 18:12:06 INFO - Running pre test command check_screen_resolution with 'bash -c screenresolution get && screenresolution list && system_profiler SPDisplaysDataType' 18:12:06 INFO - Running command: ['bash', '-c', 'screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'] in /builds/slave/test/build 18:12:06 INFO - Copy/paste: bash -c "screenresolution get && screenresolution list && system_profiler SPDisplaysDataType" 18:12:06 INFO - 2015-11-13 18:12:06.787 screenresolution[1691:13067] starting screenresolution argv=screenresolution get 18:12:06 INFO - 2015-11-13 18:12:06.790 screenresolution[1691:13067] Display 0: 1600x1200x32@60 18:12:06 INFO - 2015-11-13 18:12:06.797 screenresolution[1692:13069] starting screenresolution argv=screenresolution list 18:12:06 INFO - Available Modes on Display 0 18:12:06 INFO - 1600x1200x32@60 1152x870x32@75 1280x1024x32@75 18:12:06 INFO - 1024x768x32@75 1024x768x32@70 1024x768x32@60 18:12:06 INFO - 800x600x32@75 800x600x32@60 640x480x32@75 18:12:06 INFO - 640x480x32@60 1280x1024x32@60 1280x960x32@60 18:12:07 INFO - 1280x960x32@75 1344x1008x32@60 Graphics/Displays: 18:12:07 INFO - Intel HD Graphics 3000: 18:12:07 INFO - Chipset Model: Intel HD Graphics 3000 18:12:07 INFO - Type: GPU 18:12:07 INFO - Bus: Built-In 18:12:07 INFO - VRAM (Total): 512 MB 18:12:07 INFO - VRAM (Dynamic, Max): 10 18:12:07 INFO - Vendor: Intel (0x8086) 18:12:07 INFO - Device ID: 0x0116 18:12:07 INFO - Revision ID: 0x0009 18:12:07 INFO - Displays: 18:12:07 INFO - Display: 18:12:07 INFO - Resolution: 1600 x 1200 @ 60 Hz 18:12:07 INFO - Pixel Depth: 32-Bit Color (ARGB8888) 18:12:07 INFO - Display Serial Number: 1600x1200 60 18:12:07 INFO - Main Display: Yes 18:12:07 INFO - Mirror: Off 18:12:07 INFO - Online: Yes 18:12:07 INFO - Rotation: Supported 18:12:07 INFO - Return code: 0 18:12:07 INFO - Running post-action listener: _resource_record_post_action 18:12:07 INFO - Running post-run listener: _resource_record_post_run 18:12:08 INFO - Total resource usage - Wall time: 333s; CPU: 30.0%; Read bytes: 39511040; Write bytes: 596346880; Read time: 5192; Write time: 25648 18:12:08 INFO - install - Wall time: 42s; CPU: 30.0%; Read bytes: 208896; Write bytes: 345241600; Read time: 141; Write time: 7437 18:12:08 INFO - run-tests - Wall time: 292s; CPU: 30.0%; Read bytes: 36819968; Write bytes: 249176064; Read time: 4829; Write time: 18190 18:12:08 INFO - Running post-run listener: _upload_blobber_files 18:12:08 INFO - Blob upload gear active. 18:12:08 INFO - There are no files to upload in the directory. Skipping the blob upload mechanism ... 18:12:08 INFO - Copying logs to upload dir... 18:12:08 INFO - mkdir: /builds/slave/test/build/upload/logs program finished with exit code 0 elapsedTime=401.577665 ========= master_lag: 7.48 ========= ========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 6 mins, 49 secs) (at 2015-11-13 18:12:15.600130) ========= ========= Started set props: build_url (results: 0, elapsed: 2 secs) (at 2015-11-13 18:12:15.608799) ========= 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.5lgc4KY1WW/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.TKbTDBAdsE/Listeners TMPDIR=/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/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.010541 build_url: 'https://queue.taskcluster.net/v1/task/YuF_YRVWQt2TG1CtK1Fv1g/artifacts/public/build/firefox-45.0a1.en-US.mac.dmg' ========= master_lag: 2.84 ========= ========= Finished set props: build_url (results: 0, elapsed: 2 secs) (at 2015-11-13 18:12:18.455712) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-11-13 18:12:18.456179) ========= 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.5lgc4KY1WW/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.TKbTDBAdsE/Listeners TMPDIR=/var/folders/2v/n4b15wb56w9gwcvrw7gy6pq000000w/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.005588 ========= master_lag: 0.03 ========= ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-11-13 18:12:18.496301) ========= ========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2015-11-13 18:12:18.496723) ========= ========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2015-11-13 18:12:18.497315) ========= ========= Total master_lag: 10.57 =========