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