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