builder: mozilla-aurora_yosemite_test-other
slave: t-yosemite-r5-0025
starttime: 1446193050.92
results: success (0)
buildid: 20151029014646
builduid: e2197d6fa76745edba8eadefeb37f684
revision: 41fdefd640f368bccdeafe6446d42c0a5ad22797
========= Started set props: master (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:30.920529) =========
master: http://buildbot-master108.bb.releng.scl3.mozilla.com:8201/
========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:30.920943) =========
========= Started set props: basedir (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:30.921230) =========
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.GdR3T8lx2O/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.Xo8SBI494k/Listeners
TMPDIR=/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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.005928
basedir: '/builds/slave/test'
========= Finished set props: basedir (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:31.260826) =========
========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:31.261135) =========
========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:31.284235) =========
========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:31.284707) =========
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.GdR3T8lx2O/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.Xo8SBI494k/Listeners
TMPDIR=/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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.013091
========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:31.334270) =========
========= Started set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:31.334750) =========
script_repo_url: https://hg.mozilla.org/build/mozharness
========= Finished set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:31.335112) =========
========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:31.335384) =========
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.GdR3T8lx2O/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.Xo8SBI494k/Listeners
TMPDIR=/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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-10-30 01:17:31-- https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py
Resolving hg.mozilla.org... 63.245.215.102, 63.245.215.102, 63.245.215.25, ...
Connecting to hg.mozilla.org|63.245.215.102|:443... connected.
HTTP request sent, awaiting response... 200 Script output follows
Length: 12141 (12K) [text/x-python]
Saving to: `archiver_client.py'
0K .......... . 100% 11.5M=0.001s
2015-10-30 01:17:31 (11.5 MB/s) - `archiver_client.py' saved [12141/12141]
program finished with exit code 0
elapsedTime=0.243308
========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:31.596830) =========
========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:31.597294) =========
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.GdR3T8lx2O/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.Xo8SBI494k/Listeners
TMPDIR=/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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.070995
========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:31.685552) =========
========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:31.686314) =========
bash -c 'python archiver_client.py mozharness --repo releases/mozilla-aurora --rev 41fdefd640f368bccdeafe6446d42c0a5ad22797 --destination scripts --debug'
in dir /builds/slave/test/. (timeout 1200 secs)
watching logfiles {}
argv: ['bash', '-c', u'python archiver_client.py mozharness --repo releases/mozilla-aurora --rev 41fdefd640f368bccdeafe6446d42c0a5ad22797 --destination scripts --debug']
environment:
Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.GdR3T8lx2O/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.Xo8SBI494k/Listeners
TMPDIR=/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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-10-30 01:17:31,774 truncating revision to first 12 chars
2015-10-30 01:17:31,774 Setting DEBUG logging.
2015-10-30 01:17:31,774 attempt 1/10
2015-10-30 01:17:31,774 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/releases/mozilla-aurora/41fdefd640f3?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness
2015-10-30 01:17:32,031 unpacking tar archive at: mozilla-aurora-41fdefd640f3/testing/mozharness/
program finished with exit code 0
elapsedTime=0.513573
========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:32.217874) =========
========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:32.218182) =========
========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:32.231327) =========
========= Started tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:32.231631) =========
TinderboxPrint: script_revlink: https://hg.mozilla.org/build/mozharness/rev/production
========= Finished tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:32.232023) =========
========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 6 mins, 6 secs) (at 2015-10-30 01:17:32.232304) =========
/tools/buildbot/bin/python scripts/scripts/talos_script.py --suite other --add-option --webServer,localhost --branch-name Mozilla-Aurora --system-bits 64 --cfg talos/mac_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Mozilla-Aurora
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', 'Mozilla-Aurora', '--system-bits', '64', '--cfg', 'talos/mac_config.py', '--download-symbols', 'ondemand', '--use-talos-json', '--blob-upload-branch', 'Mozilla-Aurora']
environment:
Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.GdR3T8lx2O/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.Xo8SBI494k/Listeners
TMPDIR=/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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
01:17:32 INFO - MultiFileLogger online at 20151030 01:17:32 in /builds/slave/test
01:17:32 INFO - Run as scripts/scripts/talos_script.py --suite other --add-option --webServer,localhost --branch-name Mozilla-Aurora --system-bits 64 --cfg talos/mac_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Mozilla-Aurora
01:17:32 INFO - Guessing talos json url...
01:17:32 INFO - Using buildbot properties:
01:17:32 INFO - {
01:17:32 INFO - "properties": {
01:17:32 INFO - "buildnumber": 97,
01:17:32 INFO - "product": "firefox",
01:17:32 INFO - "script_repo_revision": "production",
01:17:32 INFO - "builddir": "mozilla-aurora_yosemite_test-other",
01:17:32 INFO - "repository": "",
01:17:32 INFO - "buildername": "Rev5 MacOSX Yosemite 10.10 mozilla-aurora talos other",
01:17:32 INFO - "buildid": "20151029014646",
01:17:32 INFO - "slavename": "t-yosemite-r5-0025",
01:17:32 INFO - "pgo_build": "False",
01:17:32 INFO - "basedir": "/builds/slave/test",
01:17:32 INFO - "project": "",
01:17:32 INFO - "platform": "yosemite",
01:17:32 INFO - "master": "http://buildbot-master108.bb.releng.scl3.mozilla.com:8201/",
01:17:32 INFO - "slavebuilddir": "test",
01:17:32 INFO - "scheduler": "tests-mozilla-aurora-macosx64-talos",
01:17:32 INFO - "branch": "mozilla-aurora",
01:17:32 INFO - "repo_path": "releases/mozilla-aurora",
01:17:32 INFO - "stage_platform": "macosx64",
01:17:32 INFO - "builduid": "e2197d6fa76745edba8eadefeb37f684",
01:17:32 INFO - "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797"
01:17:32 INFO - },
01:17:32 INFO - "sourcestamp": {
01:17:32 INFO - "repository": "",
01:17:32 INFO - "hasPatch": false,
01:17:32 INFO - "project": "",
01:17:32 INFO - "branch": "mozilla-aurora-macosx64-talos",
01:17:32 INFO - "changes": [
01:17:32 INFO - {
01:17:32 INFO - "category": null,
01:17:32 INFO - "files": [
01:17:32 INFO - {
01:17:32 INFO - "url": null,
01:17:32 INFO - "name": "https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.dmg"
01:17:32 INFO - }
01:17:32 INFO - ],
01:17:32 INFO - "repository": "",
01:17:32 INFO - "rev": "41fdefd640f368bccdeafe6446d42c0a5ad22797",
01:17:32 INFO - "who": "jyavenard@mozilla.com",
01:17:32 INFO - "when": 1446112210,
01:17:32 INFO - "number": 6592630,
01:17:32 INFO - "comments": "Bug 1218157: Only ever read from cached data in NotifyDataArrived. r=cpearce a=lizzard\n\nThe logic of queuing NotifyDataArrived and read data there was fundamentally flawed as we would continually perform reads from the same MediaResource at two different ends.\nThis would cause repetitive seeks and data being removed from the media cache. Worse, a read in NotifyDataArrived would cause another NotifyDataArrived to be scheduled.\n\nAs range-request are extremely slow, it would result in stutters and constant interruptions.\n",
01:17:32 INFO - "project": "",
01:17:32 INFO - "at": "Thu 29 Oct 2015 02:50:10",
01:17:32 INFO - "branch": "mozilla-aurora-macosx64-talos",
01:17:32 INFO - "revlink": "",
01:17:32 INFO - "properties": [
01:17:32 INFO - [
01:17:32 INFO - "buildid",
01:17:32 INFO - "20151029014646",
01:17:32 INFO - "Change"
01:17:32 INFO - ],
01:17:32 INFO - [
01:17:32 INFO - "builduid",
01:17:32 INFO - "e2197d6fa76745edba8eadefeb37f684",
01:17:32 INFO - "Change"
01:17:32 INFO - ],
01:17:32 INFO - [
01:17:32 INFO - "pgo_build",
01:17:32 INFO - "False",
01:17:32 INFO - "Change"
01:17:32 INFO - ]
01:17:32 INFO - ],
01:17:32 INFO - "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797"
01:17:32 INFO - }
01:17:32 INFO - ],
01:17:32 INFO - "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797"
01:17:32 INFO - }
01:17:32 INFO - }
01:17:32 INFO - Found installer url https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.dmg.
01:17: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')]}
01:17:32 INFO - https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.txt matches https://queue.taskcluster.net
01:17:32 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.txt
01:17:32 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.txt
01:17:32 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.txt to /builds/slave/test/build/firefox-43.0a2.en-US.mac.txt
01:17:32 INFO - retry: Calling _download_file with args: ('http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.txt', '/builds/slave/test/build/firefox-43.0a2.en-US.mac.txt'), kwargs: {}, attempt #1
01:17:34 INFO - Downloaded 107 bytes.
01:17:34 INFO - Reading from file /builds/slave/test/build/firefox-43.0a2.en-US.mac.txt
01:17:34 INFO - Contents:
01:17:34 INFO - 20151029014646
01:17:34 INFO - https://hg.mozilla.org/releases/mozilla-aurora/rev/41fdefd640f368bccdeafe6446d42c0a5ad22797
01:17:34 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
01:17:34 INFO - trying https://hg.mozilla.org/releases/mozilla-aurora/raw-file/41fdefd640/testing/talos/talos.json
01:17:34 INFO - Downloading https://hg.mozilla.org/releases/mozilla-aurora/raw-file/41fdefd640/testing/talos/talos.json to /builds/slave/test/build/talos.json
01:17:34 INFO - retry: Calling _download_file with args: ('https://hg.mozilla.org/releases/mozilla-aurora/raw-file/41fdefd640/testing/talos/talos.json', '/builds/slave/test/build/talos.json'), kwargs: {}, attempt #1
01:17:35 INFO - Downloaded 6818 bytes.
01:17:35 INFO - {'extra_options': {'android': ['--apkPath=%(apk_path)s']},
01:17:35 INFO - 'mobile-suites': {'remote-tp4m_nochrome': {'tests': ['tp4m']},
01:17:35 INFO - 'remote-trobocheck2': {'talos_options': ['--fennecIDs',
01:17:35 INFO - '../fennec_ids.txt'],
01:17:35 INFO - 'tests': ['tcheck2']},
01:17:35 INFO - 'remote-tsvgx': {'talos_options': ['--noChrome',
01:17:35 INFO - '--tppagecycles',
01:17:35 INFO - '7'],
01:17:35 INFO - 'tests': ['tsvgm']}},
01:17:35 INFO - 'suites': {'chromez': {'tests': ['tresize', 'tcanvasmark']},
01:17:35 INFO - 'chromez-e10s': {'talos_options': ['--e10s'],
01:17:35 INFO - 'tests': ['tresize', 'tcanvasmark']},
01:17:35 INFO - 'dromaeojs': {'tests': ['dromaeo_css', 'kraken', 'v8_7']},
01:17:35 INFO - 'dromaeojs-e10s': {'talos_options': ['--e10s'],
01:17:35 INFO - 'tests': ['dromaeo_css', 'kraken', 'v8_7']},
01:17:35 INFO - 'g1': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5o.manifest',
01:17:35 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/',
01:17:35 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
01:17:35 INFO - 'plugins': {'32': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash32_10_3_183_5.zip',
01:17:35 INFO - '64': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash64_11_0_d1_98.zip'},
01:17:35 INFO - 'tests': ['tp5o_scroll', 'glterrain']},
01:17:35 INFO - 'g1-e10s': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5o.manifest',
01:17:35 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/',
01:17:35 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
01:17:35 INFO - 'plugins': {'32': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash32_10_3_183_5.zip',
01:17:35 INFO - '64': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash64_11_0_d1_98.zip'},
01:17:35 INFO - 'talos_options': ['--e10s'],
01:17:35 INFO - 'tests': ['tp5o_scroll', 'glterrain']},
01:17:35 INFO - 'g2': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5o.manifest',
01:17:35 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/',
01:17:35 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
01:17:35 INFO - 'tests': ['damp', 'tps']},
01:17:35 INFO - 'g2-e10s': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5o.manifest',
01:17:35 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/',
01:17:35 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
01:17:35 INFO - 'talos_options': ['--e10s'],
01:17:35 INFO - 'tests': ['damp', 'tps']},
01:17:35 INFO - 'g3': {'tests': ['dromaeo_dom']},
01:17:35 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']},
01:17:35 INFO - 'other': {'tests': ['a11yr',
01:17:35 INFO - 'ts_paint',
01:17:35 INFO - 'tpaint',
01:17:35 INFO - 'sessionrestore',
01:17:35 INFO - 'sessionrestore_no_auto_restore']},
01:17:35 INFO - 'other-e10s': {'talos_options': ['--e10s'],
01:17:35 INFO - 'tests': ['a11yr',
01:17:35 INFO - 'ts_paint',
01:17:35 INFO - 'tpaint',
01:17:35 INFO - 'sessionrestore',
01:17:35 INFO - 'sessionrestore_no_auto_restore']},
01:17:35 INFO - 'other-e10s_l64': {'talos_options': ['--e10s'],
01:17:35 INFO - 'tests': ['a11yr',
01:17:35 INFO - 'ts_paint',
01:17:35 INFO - 'tpaint',
01:17:35 INFO - 'sessionrestore',
01:17:35 INFO - 'sessionrestore_no_auto_restore']},
01:17:35 INFO - 'other-e10s_nol64': {'talos_options': ['--e10s'],
01:17:35 INFO - 'tests': ['a11yr',
01:17:35 INFO - 'ts_paint',
01:17:35 INFO - 'tpaint',
01:17:35 INFO - 'sessionrestore',
01:17:35 INFO - 'sessionrestore_no_auto_restore']},
01:17:35 INFO - 'other_l64': {'tests': ['a11yr',
01:17:35 INFO - 'ts_paint',
01:17:35 INFO - 'tpaint',
01:17:35 INFO - 'sessionrestore',
01:17:35 INFO - 'sessionrestore_no_auto_restore']},
01:17:35 INFO - 'other_nol64': {'tests': ['a11yr',
01:17:35 INFO - 'ts_paint',
01:17:35 INFO - 'tpaint',
01:17:35 INFO - 'sessionrestore',
01:17:35 INFO - 'sessionrestore_no_auto_restore']},
01:17:35 INFO - 'svgr': {'tests': ['tsvgx',
01:17:35 INFO - 'tsvgr_opacity',
01:17:35 INFO - 'tart',
01:17:35 INFO - 'tscrollx',
01:17:35 INFO - 'cart']},
01:17:35 INFO - 'svgr-e10s': {'talos_options': ['--e10s'],
01:17:35 INFO - 'tests': ['tsvgx',
01:17:35 INFO - 'tsvgr_opacity',
01:17:35 INFO - 'tart',
01:17:35 INFO - 'tscrollx',
01:17:35 INFO - 'cart']},
01:17:35 INFO - 'tp5o': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5o.manifest',
01:17:35 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/',
01:17:35 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
01:17:35 INFO - 'plugins': {'32': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash32_10_3_183_5.zip',
01:17:35 INFO - '64': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash64_11_0_d1_98.zip'},
01:17:35 INFO - 'tests': ['tp5o']},
01:17:35 INFO - 'tp5o-e10s': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5o.manifest',
01:17:35 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/',
01:17:35 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
01:17:35 INFO - 'plugins': {'32': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash32_10_3_183_5.zip',
01:17:35 INFO - '64': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash64_11_0_d1_98.zip'},
01:17:35 INFO - 'talos_options': ['--e10s'],
01:17:35 INFO - 'tests': ['tp5o']},
01:17:35 INFO - 'xperf': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5n.manifest',
01:17:35 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/',
01:17:35 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
01:17:35 INFO - 'plugins': {'32': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash32_10_3_183_5.zip',
01:17:35 INFO - '64': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash64_11_0_d1_98.zip'},
01:17:35 INFO - 'talos_options': ['--xperf_path',
01:17:35 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'],
01:17:35 INFO - 'tests': ['tp5n']},
01:17:35 INFO - 'xperf-e10s': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5n.manifest',
01:17:35 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/',
01:17:35 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
01:17:35 INFO - 'plugins': {'32': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash32_10_3_183_5.zip',
01:17:35 INFO - '64': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash64_11_0_d1_98.zip'},
01:17:35 INFO - 'talos_options': ['--e10s',
01:17:35 INFO - '--xperf_path',
01:17:35 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"',
01:17:35 INFO - 'C:/slave/talos-data/talos/xperf.config'],
01:17:35 INFO - 'tests': ['tp5n']}},
01:17:35 INFO - 'talos.zip': {'path': '',
01:17:35 INFO - 'url': 'http://talos-bundles.pvt.build.mozilla.org/zips/talos.a6052c33d420.zip'}}
01:17:35 INFO - Dumping config to /builds/slave/test/logs/localconfig.json.
01:17:35 INFO - {'append_to_log': False,
01:17:35 INFO - 'base_work_dir': '/builds/slave/test',
01:17:35 INFO - 'blob_upload_branch': 'Mozilla-Aurora',
01:17:35 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt',
01:17:35 INFO - 'branch': 'Mozilla-Aurora',
01:17:35 INFO - 'buildbot_json_path': 'buildprops.json',
01:17:35 INFO - 'config_files': ('talos/mac_config.py',),
01:17:35 INFO - 'default_actions': ('clobber',
01:17:35 INFO - 'read-buildbot-config',
01:17:35 INFO - 'download-and-extract',
01:17:35 INFO - 'populate-webroot',
01:17:35 INFO - 'create-virtualenv',
01:17:35 INFO - 'install',
01:17:35 INFO - 'run-tests'),
01:17:35 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',),
01:17:35 INFO - 'download_minidump_stackwalk': True,
01:17:35 INFO - 'download_symbols': 'ondemand',
01:17:35 INFO - 'exes': {'python': '/tools/buildbot/bin/python',
01:17:35 INFO - 'tooltool.py': '/tools/tooltool.py',
01:17:35 INFO - 'virtualenv': ('/tools/buildbot/bin/python',
01:17:35 INFO - '/tools/misc-python/virtualenv.py')},
01:17:35 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub',
01:17:35 INFO - 'http://pypi.pub.build.mozilla.org/pub'),
01:17:35 INFO - 'installer_path': 'installer.exe',
01:17:35 INFO - 'log_level': 'info',
01:17:35 INFO - 'log_name': 'talos',
01:17:35 INFO - 'log_to_console': True,
01:17:35 INFO - 'minidump_stackwalk_path': 'macosx64-minidump_stackwalk',
01:17:35 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/macosx64/releng.manifest',
01:17:35 INFO - 'opt_config_files': (),
01:17:35 INFO - 'pip_index': False,
01:17:35 INFO - 'postflight_run_cmd_suites': ({'architectures': ('32bit', '64bit'),
01:17:35 INFO - 'cmd': ('bash',
01:17:35 INFO - '-c',
01:17:35 INFO - 'screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'),
01:17:35 INFO - 'enabled': True,
01:17:35 INFO - 'halt_on_failure': False,
01:17:35 INFO - 'name': 'check_screen_resolution'},),
01:17:35 INFO - 'preflight_run_cmd_suites': ({'architectures': ('32bit', '64bit'),
01:17:35 INFO - 'cmd': ('bash',
01:17:35 INFO - '-c',
01:17:35 INFO - 'screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'),
01:17:35 INFO - 'enabled': True,
01:17:35 INFO - 'halt_on_failure': False,
01:17:35 INFO - 'name': 'check_screen_resolution'},),
01:17:35 INFO - 'python_webserver': False,
01:17:35 INFO - 'run_cmd_checks_enabled': True,
01:17:35 INFO - 'sps_profile': False,
01:17:35 INFO - 'sps_profile_interval': 0,
01:17:35 INFO - 'suite': 'other',
01:17:35 INFO - 'system_bits': '64',
01:17:35 INFO - 'talos_extra_options': ('--webServer', 'localhost'),
01:17:35 INFO - 'talos_url': 'https://hg.mozilla.org/build/talos/archive/tip.tar.gz',
01:17:35 INFO - 'tests': (),
01:17:35 INFO - 'title': 't-yosemite-r5-0025',
01:17:35 INFO - 'tooltool_cache': '/builds/tooltool_cache',
01:17:35 INFO - 'use_talos_json': True,
01:17:35 INFO - 'virtualenv_path': '/builds/slave/test/build/venv',
01:17:35 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None},
01:17:35 INFO - 'webroot': '/builds/slave/test/../talos-data',
01:17:35 INFO - 'work_dir': 'build'}
01:17:35 INFO - #####
01:17:35 INFO - ##### Running clobber step.
01:17:35 INFO - #####
01:17:35 INFO - Running pre-action listener: _resource_record_pre_action
01:17:35 INFO - Running main action method: clobber
01:17:35 INFO - rmtree: /builds/slave/test/build
01:17:35 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1
01:17:38 INFO - Running post-action listener: _resource_record_post_action
01:17:38 INFO - #####
01:17:38 INFO - ##### Running read-buildbot-config step.
01:17:38 INFO - #####
01:17:38 INFO - Running pre-action listener: _resource_record_pre_action
01:17:38 INFO - Running main action method: read_buildbot_config
01:17:38 INFO - Using buildbot properties:
01:17:38 INFO - {
01:17:38 INFO - "properties": {
01:17:38 INFO - "buildnumber": 97,
01:17:38 INFO - "product": "firefox",
01:17:38 INFO - "script_repo_revision": "production",
01:17:38 INFO - "builddir": "mozilla-aurora_yosemite_test-other",
01:17:38 INFO - "repository": "",
01:17:38 INFO - "buildername": "Rev5 MacOSX Yosemite 10.10 mozilla-aurora talos other",
01:17:38 INFO - "buildid": "20151029014646",
01:17:38 INFO - "slavename": "t-yosemite-r5-0025",
01:17:38 INFO - "pgo_build": "False",
01:17:38 INFO - "basedir": "/builds/slave/test",
01:17:38 INFO - "project": "",
01:17:38 INFO - "platform": "yosemite",
01:17:38 INFO - "master": "http://buildbot-master108.bb.releng.scl3.mozilla.com:8201/",
01:17:38 INFO - "slavebuilddir": "test",
01:17:38 INFO - "scheduler": "tests-mozilla-aurora-macosx64-talos",
01:17:38 INFO - "branch": "mozilla-aurora",
01:17:38 INFO - "repo_path": "releases/mozilla-aurora",
01:17:38 INFO - "stage_platform": "macosx64",
01:17:38 INFO - "builduid": "e2197d6fa76745edba8eadefeb37f684",
01:17:38 INFO - "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797"
01:17:38 INFO - },
01:17:38 INFO - "sourcestamp": {
01:17:38 INFO - "repository": "",
01:17:38 INFO - "hasPatch": false,
01:17:38 INFO - "project": "",
01:17:38 INFO - "branch": "mozilla-aurora-macosx64-talos",
01:17:38 INFO - "changes": [
01:17:38 INFO - {
01:17:38 INFO - "category": null,
01:17:38 INFO - "files": [
01:17:38 INFO - {
01:17:38 INFO - "url": null,
01:17:38 INFO - "name": "https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.dmg"
01:17:38 INFO - }
01:17:38 INFO - ],
01:17:38 INFO - "repository": "",
01:17:38 INFO - "rev": "41fdefd640f368bccdeafe6446d42c0a5ad22797",
01:17:38 INFO - "who": "jyavenard@mozilla.com",
01:17:38 INFO - "when": 1446112210,
01:17:38 INFO - "number": 6592630,
01:17:38 INFO - "comments": "Bug 1218157: Only ever read from cached data in NotifyDataArrived. r=cpearce a=lizzard\n\nThe logic of queuing NotifyDataArrived and read data there was fundamentally flawed as we would continually perform reads from the same MediaResource at two different ends.\nThis would cause repetitive seeks and data being removed from the media cache. Worse, a read in NotifyDataArrived would cause another NotifyDataArrived to be scheduled.\n\nAs range-request are extremely slow, it would result in stutters and constant interruptions.\n",
01:17:38 INFO - "project": "",
01:17:38 INFO - "at": "Thu 29 Oct 2015 02:50:10",
01:17:38 INFO - "branch": "mozilla-aurora-macosx64-talos",
01:17:38 INFO - "revlink": "",
01:17:38 INFO - "properties": [
01:17:38 INFO - [
01:17:38 INFO - "buildid",
01:17:38 INFO - "20151029014646",
01:17:38 INFO - "Change"
01:17:38 INFO - ],
01:17:38 INFO - [
01:17:38 INFO - "builduid",
01:17:38 INFO - "e2197d6fa76745edba8eadefeb37f684",
01:17:38 INFO - "Change"
01:17:38 INFO - ],
01:17:38 INFO - [
01:17:38 INFO - "pgo_build",
01:17:38 INFO - "False",
01:17:38 INFO - "Change"
01:17:38 INFO - ]
01:17:38 INFO - ],
01:17:38 INFO - "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797"
01:17:38 INFO - }
01:17:38 INFO - ],
01:17:38 INFO - "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797"
01:17:38 INFO - }
01:17:38 INFO - }
01:17:38 INFO - Running post-action listener: _resource_record_post_action
01:17:38 INFO - #####
01:17:38 INFO - ##### Running download-and-extract step.
01:17:38 INFO - #####
01:17:38 INFO - Running pre-action listener: _resource_record_pre_action
01:17:38 INFO - Running main action method: download_and_extract
01:17:38 INFO - mkdir: /builds/slave/test/build/tests
01:17:38 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
01:17:38 INFO - https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/test_packages.json matches https://queue.taskcluster.net
01:17:38 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/test_packages.json
01:17:38 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/test_packages.json
01:17:38 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/test_packages.json to /builds/slave/test/build/test_packages.json
01:17:38 INFO - retry: Calling _download_file with args: ('http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/test_packages.json', '/builds/slave/test/build/test_packages.json'), kwargs: {}, attempt #1
01:17:39 INFO - Downloaded 1149 bytes.
01:17:39 INFO - Reading from file /builds/slave/test/build/test_packages.json
01:17:39 INFO - Using the following test package requirements:
01:17:39 INFO - {u'common': [u'firefox-43.0a2.en-US.mac.common.tests.zip'],
01:17:39 INFO - u'cppunittest': [u'firefox-43.0a2.en-US.mac.common.tests.zip',
01:17:39 INFO - u'firefox-43.0a2.en-US.mac.cppunittest.tests.zip'],
01:17:39 INFO - u'jittest': [u'firefox-43.0a2.en-US.mac.common.tests.zip',
01:17:39 INFO - u'jsshell-mac.zip'],
01:17:39 INFO - u'mochitest': [u'firefox-43.0a2.en-US.mac.common.tests.zip',
01:17:39 INFO - u'firefox-43.0a2.en-US.mac.mochitest.tests.zip'],
01:17:39 INFO - u'mozbase': [u'firefox-43.0a2.en-US.mac.common.tests.zip'],
01:17:39 INFO - u'reftest': [u'firefox-43.0a2.en-US.mac.common.tests.zip',
01:17:39 INFO - u'firefox-43.0a2.en-US.mac.reftest.tests.zip'],
01:17:39 INFO - u'talos': [u'firefox-43.0a2.en-US.mac.common.tests.zip',
01:17:39 INFO - u'firefox-43.0a2.en-US.mac.talos.tests.zip'],
01:17:39 INFO - u'web-platform': [u'firefox-43.0a2.en-US.mac.common.tests.zip',
01:17:39 INFO - u'firefox-43.0a2.en-US.mac.web-platform.tests.zip'],
01:17:39 INFO - u'webapprt': [u'firefox-43.0a2.en-US.mac.common.tests.zip'],
01:17:39 INFO - u'xpcshell': [u'firefox-43.0a2.en-US.mac.common.tests.zip',
01:17:39 INFO - u'firefox-43.0a2.en-US.mac.xpcshell.tests.zip']}
01:17:39 INFO - Downloading packages: [u'firefox-43.0a2.en-US.mac.common.tests.zip'] for test suite category: common
01:17:39 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')]}
01:17:39 INFO - https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.common.tests.zip matches https://queue.taskcluster.net
01:17:39 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.common.tests.zip
01:17:39 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.common.tests.zip
01:17:39 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.common.tests.zip to /builds/slave/test/build/firefox-43.0a2.en-US.mac.common.tests.zip
01:17:39 INFO - retry: Calling _download_file with args: (u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.common.tests.zip', u'/builds/slave/test/build/firefox-43.0a2.en-US.mac.common.tests.zip'), kwargs: {}, attempt #1
01:17:41 INFO - Downloaded 18106185 bytes.
01:17:41 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-43.0a2.en-US.mac.common.tests.zip'] in /builds/slave/test/build/tests
01:17:41 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-43.0a2.en-US.mac.common.tests.zip
01:17:41 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-43.0a2.en-US.mac.common.tests.zip'] with output_timeout 1760
01:17:46 INFO - Return code: 0
01:17:46 INFO - Downloading packages: [u'firefox-43.0a2.en-US.mac.common.tests.zip', u'firefox-43.0a2.en-US.mac.talos.tests.zip'] for test suite category: talos
01:17:46 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')]}
01:17:46 INFO - https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.common.tests.zip matches https://queue.taskcluster.net
01:17:46 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.common.tests.zip
01:17:46 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.common.tests.zip
01:17:46 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.common.tests.zip to /builds/slave/test/build/firefox-43.0a2.en-US.mac.common.tests.zip
01:17:46 INFO - retry: Calling _download_file with args: (u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.common.tests.zip', u'/builds/slave/test/build/firefox-43.0a2.en-US.mac.common.tests.zip'), kwargs: {}, attempt #1
01:17:53 INFO - Downloaded 18106185 bytes.
01:17:53 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-43.0a2.en-US.mac.common.tests.zip'] in /builds/slave/test/build/tests
01:17:53 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-43.0a2.en-US.mac.common.tests.zip
01:17:53 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-43.0a2.en-US.mac.common.tests.zip'] with output_timeout 1760
01:18:00 INFO - Return code: 0
01:18:00 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')]}
01:18:00 INFO - https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.talos.tests.zip matches https://queue.taskcluster.net
01:18:00 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.talos.tests.zip
01:18:00 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.talos.tests.zip
01:18:00 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.talos.tests.zip to /builds/slave/test/build/firefox-43.0a2.en-US.mac.talos.tests.zip
01:18:00 INFO - retry: Calling _download_file with args: (u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.talos.tests.zip', u'/builds/slave/test/build/firefox-43.0a2.en-US.mac.talos.tests.zip'), kwargs: {}, attempt #1
01:18:01 INFO - Downloaded 10881672 bytes.
01:18:01 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-43.0a2.en-US.mac.talos.tests.zip'] in /builds/slave/test/build/tests
01:18:01 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-43.0a2.en-US.mac.talos.tests.zip
01:18:01 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-43.0a2.en-US.mac.talos.tests.zip'] with output_timeout 1760
01:18:02 INFO - Return code: 0
01:18:02 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')]}
01:18:02 INFO - https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.dmg matches https://queue.taskcluster.net
01:18:02 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.dmg
01:18:02 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.dmg
01:18:02 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.dmg to /builds/slave/test/build/firefox-43.0a2.en-US.mac.dmg
01:18:02 INFO - retry: Calling _download_file with args: ('http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.dmg', '/builds/slave/test/build/firefox-43.0a2.en-US.mac.dmg'), kwargs: {}, attempt #1
01:18:06 INFO - Downloaded 106079073 bytes.
01:18:06 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.dmg
01:18:06 INFO - mkdir: /builds/slave/test/properties
01:18:06 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url
01:18:06 INFO - Writing to file /builds/slave/test/properties/build_url
01:18:06 INFO - Contents:
01:18:06 INFO - build_url:https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.dmg
01:18:06 INFO - Running post-action listener: _resource_record_post_action
01:18:06 INFO - Running post-action listener: _set_extra_try_arguments
01:18:06 INFO - #####
01:18:06 INFO - ##### Running populate-webroot step.
01:18:06 INFO - #####
01:18:06 INFO - Running pre-action listener: _resource_record_pre_action
01:18:06 INFO - Running main action method: populate_webroot
01:18:06 INFO - Populating webroot /builds/slave/test/../talos-data...
01:18:06 INFO - rmtree: /builds/slave/test/../talos-data/talos
01:18:06 INFO - retry: Calling rmtree with args: ('/builds/slave/test/../talos-data/talos',), kwargs: {}, attempt #1
01:18:06 INFO - copying tree: /builds/slave/test/build/tests/talos/talos to /builds/slave/test/../talos-data/talos
01:18:06 INFO - rmtree: /builds/slave/test/../talos-data/talos
01:18:06 INFO - Running post-action listener: _resource_record_post_action
01:18:06 INFO - #####
01:18:06 INFO - ##### Running create-virtualenv step.
01:18:06 INFO - #####
01:18:06 INFO - Running pre-action listener: _resource_record_pre_action
01:18:06 INFO - Running main action method: create_virtualenv
01:18:06 INFO - Creating virtualenv /builds/slave/test/build/venv
01:18:06 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
01:18:06 INFO - Copy/paste: /tools/buildbot/bin/python /tools/misc-python/virtualenv.py --no-site-packages --distribute /builds/slave/test/build/venv
01:18:07 INFO - The --no-site-packages flag is deprecated; it is now the default behavior.
01:18:07 INFO - Using real prefix '/tools/python27'
01:18:07 INFO - New python executable in /builds/slave/test/build/venv/bin/python
01:18:07 INFO - Installing distribute.............................................................................................................................................................................................done.
01:18:11 INFO - Installing pip.................done.
01:18:11 INFO - Return code: 0
01:18:11 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv
01:18: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')]}
01:18:11 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
01:18:11 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:18: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')]}
01:18:11 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
01:18:11 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:18: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', 'pip>=1.5']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1048c1530>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1048a0180>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7ff82a631990>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1047f2920>, '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 0x104542e88>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10479ca58>, '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.GdR3T8lx2O/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.Xo8SBI494k/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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
01:18: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', 'pip>=1.5'] in /builds/slave/test/build
01:18: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 pip>=1.5
01:18:11 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.GdR3T8lx2O/Render',
01:18:11 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared',
01:18:11 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared',
01:18:11 INFO - 'HOME': '/Users/cltbld',
01:18:11 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true',
01:18:11 INFO - 'LOGNAME': 'cltbld',
01:18:11 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
01:18:11 INFO - 'MOZ_NO_REMOTE': '1',
01:18:11 INFO - 'NO_EM_RESTART': '1',
01:18:11 INFO - 'PAGER': '/bin/cat',
01:18:11 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11',
01:18:11 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
01:18:11 INFO - 'PWD': '/builds/slave/test',
01:18:11 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg',
01:18:11 INFO - 'SHELL': '/bin/bash',
01:18:11 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.Xo8SBI494k/Listeners',
01:18:11 INFO - 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/',
01:18:11 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log',
01:18:11 INFO - 'USER': 'cltbld',
01:18:11 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no',
01:18:11 INFO - 'VERSIONER_PYTHON_VERSION': '2.7',
01:18:11 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
01:18:11 INFO - 'XPC_FLAGS': '0x0',
01:18:11 INFO - 'XPC_SERVICE_NAME': '0',
01:18:11 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'}
01:18:12 INFO - Ignoring indexes: https://pypi.python.org/simple/
01:18:12 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
01:18:12 INFO - Cleaning up...
01:18:12 INFO - Return code: 0
01:18:12 INFO - Installing psutil>=0.7.1 into virtualenv /builds/slave/test/build/venv
01:18:12 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')]}
01:18:12 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
01:18:12 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:18:12 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')]}
01:18:12 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
01:18:12 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:18:12 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 0x1048c1530>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1048a0180>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7ff82a631990>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1047f2920>, '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 0x104542e88>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10479ca58>, '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.GdR3T8lx2O/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.Xo8SBI494k/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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
01:18:12 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
01:18:12 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
01:18:12 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.GdR3T8lx2O/Render',
01:18:12 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared',
01:18:12 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared',
01:18:12 INFO - 'HOME': '/Users/cltbld',
01:18:12 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true',
01:18:12 INFO - 'LOGNAME': 'cltbld',
01:18:12 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
01:18:12 INFO - 'MOZ_NO_REMOTE': '1',
01:18:12 INFO - 'NO_EM_RESTART': '1',
01:18:12 INFO - 'PAGER': '/bin/cat',
01:18:12 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11',
01:18:12 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
01:18:12 INFO - 'PWD': '/builds/slave/test',
01:18:12 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg',
01:18:12 INFO - 'SHELL': '/bin/bash',
01:18:12 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.Xo8SBI494k/Listeners',
01:18:12 INFO - 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/',
01:18:12 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log',
01:18:12 INFO - 'USER': 'cltbld',
01:18:12 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no',
01:18:12 INFO - 'VERSIONER_PYTHON_VERSION': '2.7',
01:18:12 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
01:18:12 INFO - 'XPC_FLAGS': '0x0',
01:18:12 INFO - 'XPC_SERVICE_NAME': '0',
01:18:12 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'}
01:18:12 INFO - Ignoring indexes: https://pypi.python.org/simple/
01:18:12 INFO - Downloading/unpacking psutil>=0.7.1
01:18:12 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
01:18:12 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
01:18:12 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
01:18:12 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
01:18:12 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
01:18:12 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
01:18:14 INFO - Creating supposed download cache at /builds/slave/test/build/venv/cache
01:18:14 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fpsutil-3.1.1.tar.gz
01:18:14 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/psutil/setup.py) egg_info for package psutil
01:18:14 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build'
01:18:14 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects
...
01:18:15 INFO - Installing collected packages: psutil
01:18:15 INFO - Running setup.py install for psutil
01:18:15 INFO - building 'psutil._psutil_osx' extension
01:18:15 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
01:18:17 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
01:18:17 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
01:18:17 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
01:18:17 INFO - building 'psutil._psutil_posix' extension
01:18:17 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
01:18:17 WARNING - psutil/_psutil_posix.c:403:11: warning: implicit declaration of function 'ioctl' is invalid in C99 [-Wimplicit-function-declaration]
01:18:17 INFO - ret = ioctl(sock, SIOCGIFFLAGS, &ifr);
01:18:17 INFO - ^
01:18:17 INFO - 1 warning generated.
01:18:17 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
01:18:17 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build'
01:18:17 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ...
01:18:17 INFO - Successfully installed psutil
01:18:17 INFO - Cleaning up...
01:18:17 INFO - Return code: 0
01:18:17 INFO - Installing mozsystemmonitor==0.0.0 into virtualenv /builds/slave/test/build/venv
01:18:17 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
01:18:17 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
01:18:17 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:18:17 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
01:18:17 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
01:18:17 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:18:17 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 0x1048c1530>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1048a0180>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7ff82a631990>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1047f2920>, '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 0x104542e88>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10479ca58>, '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.GdR3T8lx2O/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.Xo8SBI494k/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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
01:18:17 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
01:18:17 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
01:18:17 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.GdR3T8lx2O/Render',
01:18:17 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared',
01:18:17 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared',
01:18:17 INFO - 'HOME': '/Users/cltbld',
01:18:17 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true',
01:18:17 INFO - 'LOGNAME': 'cltbld',
01:18:17 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
01:18:17 INFO - 'MOZ_NO_REMOTE': '1',
01:18:17 INFO - 'NO_EM_RESTART': '1',
01:18:17 INFO - 'PAGER': '/bin/cat',
01:18:17 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11',
01:18:17 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
01:18:17 INFO - 'PWD': '/builds/slave/test',
01:18:17 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg',
01:18:17 INFO - 'SHELL': '/bin/bash',
01:18:17 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.Xo8SBI494k/Listeners',
01:18:17 INFO - 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/',
01:18:17 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log',
01:18:17 INFO - 'USER': 'cltbld',
01:18:17 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no',
01:18:17 INFO - 'VERSIONER_PYTHON_VERSION': '2.7',
01:18:17 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
01:18:17 INFO - 'XPC_FLAGS': '0x0',
01:18:17 INFO - 'XPC_SERVICE_NAME': '0',
01:18:17 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'}
01:18:18 INFO - Ignoring indexes: https://pypi.python.org/simple/
01:18:18 INFO - Downloading/unpacking mozsystemmonitor==0.0.0
01:18: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
01:18: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
01:18: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
01:18: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
01:18: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
01:18: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
01:18:20 INFO - Downloading mozsystemmonitor-0.0.tar.gz
01:18:20 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fmozsystemmonitor-0.0.tar.gz
01:18:20 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/mozsystemmonitor/setup.py) egg_info for package mozsystemmonitor
01:18:20 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=0.7.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.0.0)
01:18:20 INFO - Installing collected packages: mozsystemmonitor
01:18:20 INFO - Running setup.py install for mozsystemmonitor
01:18:20 INFO - Successfully installed mozsystemmonitor
01:18:20 INFO - Cleaning up...
01:18:20 INFO - Return code: 0
01:18:20 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv
01:18: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')]}
01:18:20 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
01:18:20 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:18: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')]}
01:18:20 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
01:18:20 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:18:20 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 0x1048c1530>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1048a0180>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7ff82a631990>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1047f2920>, '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 0x104542e88>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10479ca58>, '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.GdR3T8lx2O/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.Xo8SBI494k/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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
01:18:20 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
01:18:20 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
01:18:20 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.GdR3T8lx2O/Render',
01:18:20 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared',
01:18:20 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared',
01:18:20 INFO - 'HOME': '/Users/cltbld',
01:18:20 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true',
01:18:20 INFO - 'LOGNAME': 'cltbld',
01:18:20 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
01:18:20 INFO - 'MOZ_NO_REMOTE': '1',
01:18:20 INFO - 'NO_EM_RESTART': '1',
01:18:20 INFO - 'PAGER': '/bin/cat',
01:18:20 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11',
01:18:20 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
01:18:20 INFO - 'PWD': '/builds/slave/test',
01:18:20 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg',
01:18:20 INFO - 'SHELL': '/bin/bash',
01:18:20 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.Xo8SBI494k/Listeners',
01:18:20 INFO - 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/',
01:18:20 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log',
01:18:20 INFO - 'USER': 'cltbld',
01:18:20 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no',
01:18:20 INFO - 'VERSIONER_PYTHON_VERSION': '2.7',
01:18:20 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
01:18:20 INFO - 'XPC_FLAGS': '0x0',
01:18:20 INFO - 'XPC_SERVICE_NAME': '0',
01:18:20 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'}
01:18:21 INFO - Ignoring indexes: https://pypi.python.org/simple/
01:18:21 INFO - Downloading/unpacking blobuploader==1.2.4
01:18:21 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
01:18:21 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
01:18:21 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
01:18:21 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
01:18:21 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
01:18:21 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
01:18:23 INFO - Downloading blobuploader-1.2.4.tar.gz
01:18:23 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fblobuploader-1.2.4.tar.gz
01:18:23 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blobuploader/setup.py) egg_info for package blobuploader
01:18:23 INFO - Downloading/unpacking requests==1.2.3. (from blobuploader==1.2.4)
01:18:23 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
01:18:23 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
01:18:23 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
01:18:23 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
01:18:23 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
01:18:23 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
01:18:24 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Frequests-1.2.3.tar.gz
01:18:24 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests
01:18:24 INFO - Downloading/unpacking docopt==0.6.1 (from blobuploader==1.2.4)
01:18:24 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
01:18:24 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
01:18:24 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
01:18:24 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
01:18:24 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
01:18:24 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
01:18:24 INFO - Downloading docopt-0.6.1.tar.gz
01:18:24 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fdocopt-0.6.1.tar.gz
01:18:24 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/docopt/setup.py) egg_info for package docopt
01:18:24 INFO - Installing collected packages: blobuploader, requests, docopt
01:18:24 INFO - Running setup.py install for blobuploader
01:18:24 INFO - changing mode of build/scripts-2.7/blobberc.py from 664 to 775
01:18:25 INFO - changing mode of /builds/slave/test/build/venv/bin/blobberc.py to 775
01:18:25 INFO - Running setup.py install for requests
01:18:25 INFO - Running setup.py install for docopt
01:18:25 INFO - Successfully installed blobuploader requests docopt
01:18:25 INFO - Cleaning up...
01:18:25 INFO - Return code: 0
01:18:25 INFO - Installing None into virtualenv /builds/slave/test/build/venv
01:18:25 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')]}
01:18:25 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
01:18:25 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:18:25 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')]}
01:18:25 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
01:18:25 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:18:25 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 0x1048c1530>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1048a0180>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7ff82a631990>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1047f2920>, '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 0x104542e88>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10479ca58>, '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.GdR3T8lx2O/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.Xo8SBI494k/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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
01:18:25 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
01:18:25 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
01:18:25 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.GdR3T8lx2O/Render',
01:18:25 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared',
01:18:25 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared',
01:18:25 INFO - 'HOME': '/Users/cltbld',
01:18:25 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true',
01:18:25 INFO - 'LOGNAME': 'cltbld',
01:18:25 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
01:18:25 INFO - 'MOZ_NO_REMOTE': '1',
01:18:25 INFO - 'NO_EM_RESTART': '1',
01:18:25 INFO - 'PAGER': '/bin/cat',
01:18:25 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11',
01:18:25 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
01:18:25 INFO - 'PWD': '/builds/slave/test',
01:18:25 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg',
01:18:25 INFO - 'SHELL': '/bin/bash',
01:18:25 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.Xo8SBI494k/Listeners',
01:18:25 INFO - 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/',
01:18:25 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log',
01:18:25 INFO - 'USER': 'cltbld',
01:18:25 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no',
01:18:25 INFO - 'VERSIONER_PYTHON_VERSION': '2.7',
01:18:25 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
01:18:25 INFO - 'XPC_FLAGS': '0x0',
01:18:25 INFO - 'XPC_SERVICE_NAME': '0',
01:18:25 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'}
01:18:26 INFO - Ignoring indexes: https://pypi.python.org/simple/
01:18:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser
01:18:26 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-Br_0wE-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser
01:18:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash
01:18:26 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-qFAhO0-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash
01:18:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug
01:18:26 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-Gfuw8q-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug
01:18:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice
01:18:26 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-uaqptv-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice
01:18:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile
01:18:26 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-ZfzLQC-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile
01:18:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd
01:18:26 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-fj6NOw-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd
01:18:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo
01:18:26 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-rxtxpQ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo
01:18:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall
01:18:26 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-anKpqG-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall
01:18:27 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak
01:18:27 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-303xvN-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak
01:18:27 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog
01:18:27 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-WBGm44-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog
01:18:27 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork
01:18:27 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-HJXegv-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork
01:18:27 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess
01:18:27 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-TGtNoP-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess
01:18:27 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile
01:18:27 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-QeCXQE-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile
01:18:27 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner
01:18:27 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-YAULeG-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner
01:18:27 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot
01:18:27 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-AQ2TRU-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot
01:18:27 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest
01:18:27 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-vNnZXj-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest
01:18:28 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion
01:18:28 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-ogn4CE-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion
01:18:28 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion
01:18:28 INFO - Running setup.py install for manifestparser
01:18:28 INFO - Installing manifestparser script to /builds/slave/test/build/venv/bin
01:18:28 INFO - Running setup.py install for mozcrash
01:18:28 INFO - Running setup.py install for mozdebug
01:18:28 INFO - Running setup.py install for mozdevice
01:18:28 INFO - Installing sutini script to /builds/slave/test/build/venv/bin
01:18:28 INFO - Installing dm script to /builds/slave/test/build/venv/bin
01:18:28 INFO - Running setup.py install for mozfile
01:18:29 INFO - Running setup.py install for mozhttpd
01:18:29 INFO - Installing mozhttpd script to /builds/slave/test/build/venv/bin
01:18:29 INFO - Running setup.py install for mozinfo
01:18:29 INFO - Installing mozinfo script to /builds/slave/test/build/venv/bin
01:18:29 INFO - Running setup.py install for mozInstall
01:18:29 INFO - Installing moz_remove_from_system script to /builds/slave/test/build/venv/bin
01:18:29 INFO - Installing mozuninstall script to /builds/slave/test/build/venv/bin
01:18:29 INFO - Installing mozinstall script to /builds/slave/test/build/venv/bin
01:18:29 INFO - Installing moz_add_to_system script to /builds/slave/test/build/venv/bin
01:18:29 INFO - Running setup.py install for mozleak
01:18:29 INFO - Running setup.py install for mozlog
01:18:29 INFO - Installing structlog script to /builds/slave/test/build/venv/bin
01:18:29 INFO - Running setup.py install for moznetwork
01:18:30 INFO - Installing moznetwork script to /builds/slave/test/build/venv/bin
01:18:30 INFO - Running setup.py install for mozprocess
01:18:30 INFO - Running setup.py install for mozprofile
01:18:30 INFO - Installing mozprofile script to /builds/slave/test/build/venv/bin
01:18:30 INFO - Installing diff-profiles script to /builds/slave/test/build/venv/bin
01:18:30 INFO - Installing view-profile script to /builds/slave/test/build/venv/bin
01:18:30 INFO - Running setup.py install for mozrunner
01:18:30 INFO - Installing mozrunner script to /builds/slave/test/build/venv/bin
01:18:30 INFO - Running setup.py install for mozscreenshot
01:18:30 INFO - Running setup.py install for moztest
01:18:30 INFO - Running setup.py install for mozversion
01:18:31 INFO - Installing mozversion script to /builds/slave/test/build/venv/bin
01:18:31 INFO - Successfully installed manifestparser mozcrash mozdebug mozdevice mozfile mozhttpd mozinfo mozInstall mozleak mozlog moznetwork mozprocess mozprofile mozrunner mozscreenshot moztest mozversion
01:18:31 INFO - Cleaning up...
01:18:31 INFO - Return code: 0
01:18:31 INFO - Installing None into virtualenv /builds/slave/test/build/venv
01:18: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')]}
01:18:31 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
01:18:31 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:18: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')]}
01:18:31 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
01:18:31 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:18:31 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 0x1048c1530>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1048a0180>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7ff82a631990>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1047f2920>, '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 0x104542e88>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10479ca58>, '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.GdR3T8lx2O/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.Xo8SBI494k/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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
01:18:31 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
01:18:31 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
01:18:31 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.GdR3T8lx2O/Render',
01:18:31 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared',
01:18:31 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared',
01:18:31 INFO - 'HOME': '/Users/cltbld',
01:18:31 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true',
01:18:31 INFO - 'LOGNAME': 'cltbld',
01:18:31 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
01:18:31 INFO - 'MOZ_NO_REMOTE': '1',
01:18:31 INFO - 'NO_EM_RESTART': '1',
01:18:31 INFO - 'PAGER': '/bin/cat',
01:18:31 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11',
01:18:31 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
01:18:31 INFO - 'PWD': '/builds/slave/test',
01:18:31 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg',
01:18:31 INFO - 'SHELL': '/bin/bash',
01:18:31 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.Xo8SBI494k/Listeners',
01:18:31 INFO - 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/',
01:18:31 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log',
01:18:31 INFO - 'USER': 'cltbld',
01:18:31 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no',
01:18:31 INFO - 'VERSIONER_PYTHON_VERSION': '2.7',
01:18:31 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
01:18:31 INFO - 'XPC_FLAGS': '0x0',
01:18:31 INFO - 'XPC_SERVICE_NAME': '0',
01:18:31 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'}
01:18:31 INFO - Ignoring indexes: https://pypi.python.org/simple/
01:18:31 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser
01:18:31 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-AXrgc7-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser
01:18:31 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))
01:18:31 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash
01:18:31 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-z706wU-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash
01:18:31 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))
01:18:31 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug
01:18:31 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-56qKrC-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug
01:18:31 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))
01:18:31 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice
01:18:31 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-gfVrTX-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice
01:18:32 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdevice==0.46 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))
01:18:32 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile
01:18:32 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-7H0gQe-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile
01:18:32 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))
01:18:32 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd
01:18:32 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-1LvpBu-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd
01:18:32 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))
01:18:32 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo
01:18:32 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-3RMobA-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo
01:18:32 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo==0.8 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))
01:18:32 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall
01:18:32 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-1D8rMD-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall
01:18:32 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))
01:18:32 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak
01:18:32 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-DRrGAD-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak
01:18:32 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))
01:18:32 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog
01:18:32 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-giQafB-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog
01:18:32 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))
01:18:32 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork
01:18:32 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-mUOX2O-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork
01:18:32 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))
01:18:32 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess
01:18:32 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-pojTyV-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess
01:18:33 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))
01:18:33 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile
01:18:33 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-K7it1f-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile
01:18:33 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))
01:18:33 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner
01:18:33 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-i2FnsM-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner
01:18:33 INFO - Requirement already satisfied (use --upgrade to upgrade): mozrunner==6.10 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))
01:18:33 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot
01:18:33 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-2voBmn-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot
01:18:33 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))
01:18:33 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest
01:18:33 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-UQuPw3-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest
01:18:33 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))
01:18:33 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion
01:18:33 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-8AkFgt-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion
01:18:33 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))
01:18:33 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))
01:18:33 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))
01:18:33 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))
01:18:33 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.46->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4))
01:18:33 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.46->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4))
01:18:33 INFO - Downloading/unpacking blessings>=1.3 (from mozlog==3.0->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10))
01:18:33 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
01:18:33 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
01:18:33 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
01:18:33 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
01:18:33 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
01:18:33 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
01:18:36 INFO - Downloading blessings-1.5.1.tar.gz
01:18:36 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
01:18:36 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blessings/setup.py) egg_info for package blessings
01:18:36 INFO - Installing collected packages: blessings
01:18:36 INFO - Running setup.py install for blessings
01:18:36 INFO - Successfully installed blessings
01:18:36 INFO - Cleaning up...
01:18:36 INFO - Return code: 0
01:18:36 INFO - Done creating virtualenv /builds/slave/test/build/venv.
01:18:36 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze']
01:18:36 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze
01:18:36 INFO - Reading from file tmpfile_stdout
01:18:36 INFO - Current package versions:
01:18:36 INFO - blessings == 1.5.1
01:18:36 INFO - blobuploader == 1.2.4
01:18:36 INFO - docopt == 0.6.1
01:18:36 INFO - manifestparser == 1.1
01:18:36 INFO - mozInstall == 1.12
01:18:36 INFO - mozcrash == 0.16
01:18:36 INFO - mozdebug == 0.1
01:18:36 INFO - mozdevice == 0.46
01:18:36 INFO - mozfile == 1.2
01:18:36 INFO - mozhttpd == 0.7
01:18:36 INFO - mozinfo == 0.8
01:18:36 INFO - mozleak == 0.1
01:18:36 INFO - mozlog == 3.0
01:18:36 INFO - moznetwork == 0.27
01:18:36 INFO - mozprocess == 0.22
01:18:36 INFO - mozprofile == 0.27
01:18:36 INFO - mozrunner == 6.10
01:18:36 INFO - mozscreenshot == 0.1
01:18:36 INFO - mozsystemmonitor == 0.0
01:18:36 INFO - moztest == 0.7
01:18:36 INFO - mozversion == 1.4
01:18:36 INFO - psutil == 3.1.1
01:18:36 INFO - requests == 1.2.3
01:18:36 INFO - wsgiref == 0.1.2
01:18:36 INFO - Installing None into virtualenv /builds/slave/test/build/venv
01:18:36 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')]}
01:18:36 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
01:18:36 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:18:36 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')]}
01:18:36 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
01:18:36 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:18:36 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 0x1048c1530>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1048a0180>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7ff82a631990>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1047f2920>, '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 0x104542e88>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10479ca58>, '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.GdR3T8lx2O/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.Xo8SBI494k/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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
01:18:36 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
01:18:36 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
01:18:36 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.GdR3T8lx2O/Render',
01:18:36 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared',
01:18:36 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared',
01:18:36 INFO - 'HOME': '/Users/cltbld',
01:18:36 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true',
01:18:36 INFO - 'LOGNAME': 'cltbld',
01:18:36 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
01:18:36 INFO - 'MOZ_NO_REMOTE': '1',
01:18:36 INFO - 'NO_EM_RESTART': '1',
01:18:36 INFO - 'PAGER': '/bin/cat',
01:18:36 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11',
01:18:36 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
01:18:36 INFO - 'PWD': '/builds/slave/test',
01:18:36 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg',
01:18:36 INFO - 'SHELL': '/bin/bash',
01:18:36 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.Xo8SBI494k/Listeners',
01:18:36 INFO - 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/',
01:18:36 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log',
01:18:36 INFO - 'USER': 'cltbld',
01:18:36 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no',
01:18:36 INFO - 'VERSIONER_PYTHON_VERSION': '2.7',
01:18:36 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
01:18:36 INFO - 'XPC_FLAGS': '0x0',
01:18:36 INFO - 'XPC_SERVICE_NAME': '0',
01:18:36 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'}
01:18:37 INFO - Ignoring indexes: https://pypi.python.org/simple/
01:18:37 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))
01:18:37 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))
01:18:37 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))
01:18:37 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))
01:18:37 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))
01:18:37 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))
01:18:37 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))
01:18:37 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))
01:18:37 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))
01:18:37 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))
01:18:37 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))
01:18:37 INFO - Cleaning up...
01:18:37 INFO - Return code: 0
01:18:37 INFO - Running post-action listener: _resource_record_post_action
01:18:37 INFO - Running post-action listener: _start_resource_monitoring
01:18:37 INFO - Starting resource monitoring.
01:18:37 INFO - #####
01:18:37 INFO - ##### Running install step.
01:18:37 INFO - #####
01:18:37 INFO - Running pre-action listener: _resource_record_pre_action
01:18:37 INFO - Running main action method: install
01:18:37 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze']
01:18:37 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze
01:18:37 INFO - Reading from file tmpfile_stdout
01:18:37 INFO - Detecting whether we're running mozinstall >=1.0...
01:18:37 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h']
01:18:37 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h
01:18:37 INFO - Reading from file tmpfile_stdout
01:18:37 INFO - Output received:
01:18:37 INFO - Usage: mozinstall [options] installer
01:18:37 INFO - Options:
01:18:37 INFO - -h, --help show this help message and exit
01:18:37 INFO - -d DEST, --destination=DEST
01:18:37 INFO - Directory to install application into. [default:
01:18:37 INFO - "/builds/slave/test"]
01:18:37 INFO - --app=APP Application being installed. [default: firefox]
01:18:37 INFO - mkdir: /builds/slave/test/build/application
01:18:37 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '/builds/slave/test/build/firefox-43.0a2.en-US.mac.dmg', '--destination', '/builds/slave/test/build/application']
01:18:37 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall /builds/slave/test/build/firefox-43.0a2.en-US.mac.dmg --destination /builds/slave/test/build/application
01:19:15 INFO - Reading from file tmpfile_stdout
01:19:15 INFO - Output received:
01:19:15 INFO - /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox
01:19:15 INFO - Running post-action listener: _resource_record_post_action
01:19:15 INFO - #####
01:19:15 INFO - ##### Running run-tests step.
01:19:15 INFO - #####
01:19:15 INFO - Running pre-action listener: _resource_record_pre_action
01:19:15 INFO - Running main action method: run_tests
01:19:15 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version']
01:19:15 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version
01:19:15 INFO - Python 2.7.3
01:19:15 INFO - Return code: 0
01:19:15 INFO - grabbing minidump binary from tooltool
01:19: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')]}
01:19: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 0x1047f2920>, '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 0x104542e88>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10479ca58>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1
01:19: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
01:19: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
01:19:15 INFO - INFO - File macosx64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache
01:19:15 INFO - Return code: 0
01:19:15 INFO - Chmoding /builds/slave/test/build/macosx64-minidump_stackwalk to 0755
01:19:15 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir
01:19:15 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir
01:19:15 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/macosx64-minidump_stackwalk
01:19:15 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir
01:19:15 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--debug', '--branchName', 'Mozilla-Aurora', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.crashreporter-symbols.zip', '--activeTests', 'a11yr:ts_paint:tpaint:sessionrestore:sessionrestore_no_auto_restore', '--executablePath', '/builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox', '--title', 't-yosemite-r5-0025', '--webServer', 'localhost'] in /builds/slave/test/build
01:19:15 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/tests/talos/talos/run_tests.py --debug --branchName Mozilla-Aurora --symbolsPath https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.crashreporter-symbols.zip --activeTests a11yr:ts_paint:tpaint:sessionrestore:sessionrestore_no_auto_restore --executablePath /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox --title t-yosemite-r5-0025 --webServer localhost
01:19:15 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.GdR3T8lx2O/Render',
01:19:15 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared',
01:19:15 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared',
01:19:15 INFO - 'HOME': '/Users/cltbld',
01:19:15 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true',
01:19:15 INFO - 'LOGNAME': 'cltbld',
01:19:15 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir',
01:19:15 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/macosx64-minidump_stackwalk',
01:19:15 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
01:19:15 INFO - 'MOZ_NO_REMOTE': '1',
01:19:15 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir',
01:19:15 INFO - 'NO_EM_RESTART': '1',
01:19:15 INFO - 'PAGER': '/bin/cat',
01:19:15 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11',
01:19:15 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
01:19:15 INFO - 'PWD': '/builds/slave/test',
01:19:15 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos',
01:19:15 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg',
01:19:15 INFO - 'SHELL': '/bin/bash',
01:19:15 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.Xo8SBI494k/Listeners',
01:19:15 INFO - 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/',
01:19:15 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log',
01:19:15 INFO - 'USER': 'cltbld',
01:19:15 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no',
01:19:15 INFO - 'VERSIONER_PYTHON_VERSION': '2.7',
01:19:15 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
01:19:15 INFO - 'XPC_FLAGS': '0x0',
01:19:15 INFO - 'XPC_SERVICE_NAME': '0',
01:19:15 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'}
01:19:15 INFO - Calling ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--debug', '--branchName', 'Mozilla-Aurora', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.crashreporter-symbols.zip', '--activeTests', 'a11yr:ts_paint:tpaint:sessionrestore:sessionrestore_no_auto_restore', '--executablePath', '/builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox', '--title', 't-yosemite-r5-0025', '--webServer', 'localhost'] with output_timeout 3600
01:19:16 INFO - mozversion INFO | application_buildid: 20151029014646
01:19:16 INFO - mozversion INFO | application_changeset: 41fdefd640f368bccdeafe6446d42c0a5ad22797
01:19:16 INFO - mozversion INFO | application_display_name: FirefoxDeveloperEdition
01:19:16 INFO - mozversion INFO | application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384}
01:19:16 INFO - mozversion INFO | application_name: Firefox
01:19:16 INFO - mozversion INFO | application_remotingname: firefox-dev
01:19:16 INFO - mozversion INFO | application_repository: https://hg.mozilla.org/releases/mozilla-aurora
01:19:16 INFO - mozversion INFO | application_vendor: Mozilla
01:19:16 INFO - mozversion INFO | application_version: 43.0a2
01:19:16 INFO - mozversion INFO | platform_buildid: 20151029014646
01:19:16 INFO - mozversion INFO | platform_changeset: 41fdefd640f368bccdeafe6446d42c0a5ad22797
01:19:16 INFO - mozversion INFO | platform_repository: https://hg.mozilla.org/releases/mozilla-aurora
01:19:16 INFO - mozversion INFO | platform_version: 43.0a2
01:19:16 INFO - 2015-10-30 01:19:16,148 DEBUG : using testdate: 1446193156
01:19:16 INFO - 2015-10-30 01:19:16,148 DEBUG : actual date: 1446193156
01:19:16 INFO - 2015-10-30 01:19:16,209 INFO : Starting test suite t-yosemite-r5-0025
01:19:16 INFO - 2015-10-30 01:19:16,209 INFO : Starting test a11yr
01:19:16 INFO - 2015-10-30 01:19:16,209 DEBUG : operating with platform_type : mac_
01:19:16 INFO - 2015-10-30 01:19:16,210 INFO : Initialising browser for a11yr test...
01:19:16 INFO - 2015-10-30 01:19:16,244 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpbxOdYQ/profile http://localhost/getInfo.html
01:19:19 INFO - 2015-10-30 01:19:19,865 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
01:19:19 INFO - 2015-10-30 01:19:19,865 DEBUG : BROWSER_OUTPUT: colorDepth:24
01:19:19 INFO - 2015-10-30 01:19:19,866 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/689
01:19:19 INFO - 2015-10-30 01:19:19,866 DEBUG : BROWSER_OUTPUT: __metrics
01:19:19 INFO - 2015-10-30 01:19:19,884 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]
01:19:20 INFO - 2015-10-30 01:19:20,491 INFO : Browser initialized.
01:19:20 INFO - 2015-10-30 01:19:20,491 INFO : Running cycle 1/1 for a11yr test...
01:19:20 INFO - 2015-10-30 01:19:20,492 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpbxOdYQ/profile -tp file:/builds/slave/test/build/tests/talos/talos/page_load_test/a11y/a11y.manifest -tpchrome -tpmozafterpaint -tpnoisy -tpcycles 1 -tppagecycles 25
01:19:32 INFO - 2015-10-30 01:19:32,458 DEBUG : BROWSER_OUTPUT: RSS: Main: 195084288
01:19:32 INFO - 2015-10-30 01:19:32,458 DEBUG : BROWSER_OUTPUT:
01:19:33 INFO - 2015-10-30 01:19:33,564 DEBUG : BROWSER_OUTPUT: Cycle 1(1): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:19:34 INFO - 2015-10-30 01:19:34,175 DEBUG : BROWSER_OUTPUT: RSS: Main: 245010432
01:19:34 INFO - 2015-10-30 01:19:34,175 DEBUG : BROWSER_OUTPUT:
01:19:35 INFO - 2015-10-30 01:19:35,449 DEBUG : BROWSER_OUTPUT: Cycle 1(2): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:19:36 INFO - 2015-10-30 01:19:36,119 DEBUG : BROWSER_OUTPUT: RSS: Main: 260526080
01:19:36 INFO - 2015-10-30 01:19:36,120 DEBUG : BROWSER_OUTPUT:
01:19:37 INFO - 2015-10-30 01:19:37,398 DEBUG : BROWSER_OUTPUT: Cycle 1(3): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:19:38 INFO - 2015-10-30 01:19:38,063 DEBUG : BROWSER_OUTPUT: RSS: Main: 260419584
01:19:38 INFO - 2015-10-30 01:19:38,063 DEBUG : BROWSER_OUTPUT:
01:19:39 INFO - 2015-10-30 01:19:39,362 DEBUG : BROWSER_OUTPUT: Cycle 1(4): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:19:40 INFO - 2015-10-30 01:19:40,032 DEBUG : BROWSER_OUTPUT: RSS: Main: 261636096
01:19:40 INFO - 2015-10-30 01:19:40,032 DEBUG : BROWSER_OUTPUT:
01:19:41 INFO - 2015-10-30 01:19:41,318 DEBUG : BROWSER_OUTPUT: Cycle 1(5): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:19:41 INFO - 2015-10-30 01:19:41,995 DEBUG : BROWSER_OUTPUT: RSS: Main: 263385088
01:19:41 INFO - 2015-10-30 01:19:41,995 DEBUG : BROWSER_OUTPUT:
01:19:43 INFO - 2015-10-30 01:19:43,303 DEBUG : BROWSER_OUTPUT: Cycle 1(6): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:19:43 INFO - 2015-10-30 01:19:43,980 DEBUG : BROWSER_OUTPUT: RSS: Main: 264544256
01:19:43 INFO - 2015-10-30 01:19:43,981 DEBUG : BROWSER_OUTPUT:
01:19:45 INFO - 2015-10-30 01:19:45,290 DEBUG : BROWSER_OUTPUT: Cycle 1(7): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:19:45 INFO - 2015-10-30 01:19:45,974 DEBUG : BROWSER_OUTPUT: RSS: Main: 264585216
01:19:45 INFO - 2015-10-30 01:19:45,974 DEBUG : BROWSER_OUTPUT:
01:19:47 INFO - 2015-10-30 01:19:47,310 DEBUG : BROWSER_OUTPUT: Cycle 1(8): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:19:47 INFO - 2015-10-30 01:19:47,981 DEBUG : BROWSER_OUTPUT: RSS: Main: 265367552
01:19:47 INFO - 2015-10-30 01:19:47,982 DEBUG : BROWSER_OUTPUT:
01:19:49 INFO - 2015-10-30 01:19:49,296 DEBUG : BROWSER_OUTPUT: Cycle 1(9): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:19:49 INFO - 2015-10-30 01:19:49,968 DEBUG : BROWSER_OUTPUT: RSS: Main: 264306688
01:19:49 INFO - 2015-10-30 01:19:49,968 DEBUG : BROWSER_OUTPUT:
01:19:51 INFO - 2015-10-30 01:19:51,247 DEBUG : BROWSER_OUTPUT: Cycle 1(10): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:19:51 INFO - 2015-10-30 01:19:51,921 DEBUG : BROWSER_OUTPUT: RSS: Main: 265670656
01:19:51 INFO - 2015-10-30 01:19:51,921 DEBUG : BROWSER_OUTPUT:
01:19:53 INFO - 2015-10-30 01:19:53,112 DEBUG : BROWSER_OUTPUT: Cycle 1(11): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:19:53 INFO - 2015-10-30 01:19:53,794 DEBUG : BROWSER_OUTPUT: RSS: Main: 264298496
01:19:53 INFO - 2015-10-30 01:19:53,794 DEBUG : BROWSER_OUTPUT:
01:19:55 INFO - 2015-10-30 01:19:55,087 DEBUG : BROWSER_OUTPUT: Cycle 1(12): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:19:55 INFO - 2015-10-30 01:19:55,773 DEBUG : BROWSER_OUTPUT: RSS: Main: 265449472
01:19:55 INFO - 2015-10-30 01:19:55,773 DEBUG : BROWSER_OUTPUT:
01:19:57 INFO - 2015-10-30 01:19:57,107 DEBUG : BROWSER_OUTPUT: Cycle 1(13): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:19:57 INFO - 2015-10-30 01:19:57,785 DEBUG : BROWSER_OUTPUT: RSS: Main: 265805824
01:19:57 INFO - 2015-10-30 01:19:57,785 DEBUG : BROWSER_OUTPUT:
01:19:59 INFO - 2015-10-30 01:19:59,053 DEBUG : BROWSER_OUTPUT: Cycle 1(14): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:19:59 INFO - 2015-10-30 01:19:59,729 DEBUG : BROWSER_OUTPUT: RSS: Main: 267010048
01:19:59 INFO - 2015-10-30 01:19:59,729 DEBUG : BROWSER_OUTPUT:
01:20:00 INFO - 2015-10-30 01:20:00,941 DEBUG : BROWSER_OUTPUT: Cycle 1(15): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:01 INFO - 2015-10-30 01:20:01,628 DEBUG : BROWSER_OUTPUT: RSS: Main: 265338880
01:20:01 INFO - 2015-10-30 01:20:01,628 DEBUG : BROWSER_OUTPUT:
01:20:02 INFO - 2015-10-30 01:20:02,838 DEBUG : BROWSER_OUTPUT: Cycle 1(16): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:03 INFO - 2015-10-30 01:20:03,514 DEBUG : BROWSER_OUTPUT: RSS: Main: 266481664
01:20:03 INFO - 2015-10-30 01:20:03,515 DEBUG : BROWSER_OUTPUT:
01:20:04 INFO - 2015-10-30 01:20:04,678 DEBUG : BROWSER_OUTPUT: Cycle 1(17): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:05 INFO - 2015-10-30 01:20:05,369 DEBUG : BROWSER_OUTPUT: RSS: Main: 264957952
01:20:05 INFO - 2015-10-30 01:20:05,369 DEBUG : BROWSER_OUTPUT:
01:20:06 INFO - 2015-10-30 01:20:06,640 DEBUG : BROWSER_OUTPUT: Cycle 1(18): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:07 INFO - 2015-10-30 01:20:07,326 DEBUG : BROWSER_OUTPUT: RSS: Main: 265977856
01:20:07 INFO - 2015-10-30 01:20:07,326 DEBUG : BROWSER_OUTPUT:
01:20:08 INFO - 2015-10-30 01:20:08,593 DEBUG : BROWSER_OUTPUT: Cycle 1(19): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:09 INFO - 2015-10-30 01:20:09,270 DEBUG : BROWSER_OUTPUT: RSS: Main: 265375744
01:20:09 INFO - 2015-10-30 01:20:09,270 DEBUG : BROWSER_OUTPUT:
01:20:10 INFO - 2015-10-30 01:20:10,596 DEBUG : BROWSER_OUTPUT: Cycle 1(20): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:11 INFO - 2015-10-30 01:20:11,276 DEBUG : BROWSER_OUTPUT: RSS: Main: 267128832
01:20:11 INFO - 2015-10-30 01:20:11,276 DEBUG : BROWSER_OUTPUT:
01:20:12 INFO - 2015-10-30 01:20:12,572 DEBUG : BROWSER_OUTPUT: Cycle 1(21): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:13 INFO - 2015-10-30 01:20:13,258 DEBUG : BROWSER_OUTPUT: RSS: Main: 266661888
01:20:13 INFO - 2015-10-30 01:20:13,258 DEBUG : BROWSER_OUTPUT:
01:20:14 INFO - 2015-10-30 01:20:14,472 DEBUG : BROWSER_OUTPUT: Cycle 1(22): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:15 INFO - 2015-10-30 01:20:15,159 DEBUG : BROWSER_OUTPUT: RSS: Main: 266252288
01:20:15 INFO - 2015-10-30 01:20:15,159 DEBUG : BROWSER_OUTPUT:
01:20:16 INFO - 2015-10-30 01:20:16,414 DEBUG : BROWSER_OUTPUT: Cycle 1(23): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:17 INFO - 2015-10-30 01:20:17,093 DEBUG : BROWSER_OUTPUT: RSS: Main: 267026432
01:20:17 INFO - 2015-10-30 01:20:17,094 DEBUG : BROWSER_OUTPUT:
01:20:18 INFO - 2015-10-30 01:20:18,380 DEBUG : BROWSER_OUTPUT: Cycle 1(24): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:19 INFO - 2015-10-30 01:20:19,068 DEBUG : BROWSER_OUTPUT: RSS: Main: 267440128
01:20:19 INFO - 2015-10-30 01:20:19,068 DEBUG : BROWSER_OUTPUT:
01:20:20 INFO - 2015-10-30 01:20:20,351 DEBUG : BROWSER_OUTPUT: Cycle 1(25): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:21 INFO - 2015-10-30 01:20:21,029 DEBUG : BROWSER_OUTPUT: RSS: Main: 272949248
01:20:21 INFO - 2015-10-30 01:20:21,030 DEBUG : BROWSER_OUTPUT:
01:20:21 INFO - 2015-10-30 01:20:21,816 DEBUG : BROWSER_OUTPUT: Cycle 1(1): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:22 INFO - 2015-10-30 01:20:22,400 DEBUG : BROWSER_OUTPUT: RSS: Main: 270348288
01:20:22 INFO - 2015-10-30 01:20:22,400 DEBUG : BROWSER_OUTPUT:
01:20:23 INFO - 2015-10-30 01:20:23,126 DEBUG : BROWSER_OUTPUT: Cycle 1(2): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:23 INFO - 2015-10-30 01:20:23,753 DEBUG : BROWSER_OUTPUT: RSS: Main: 276086784
01:20:23 INFO - 2015-10-30 01:20:23,753 DEBUG : BROWSER_OUTPUT:
01:20:24 INFO - 2015-10-30 01:20:24,486 DEBUG : BROWSER_OUTPUT: Cycle 1(3): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:25 INFO - 2015-10-30 01:20:25,080 DEBUG : BROWSER_OUTPUT: RSS: Main: 275271680
01:20:25 INFO - 2015-10-30 01:20:25,080 DEBUG : BROWSER_OUTPUT:
01:20:25 INFO - 2015-10-30 01:20:25,831 DEBUG : BROWSER_OUTPUT: Cycle 1(4): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:26 INFO - 2015-10-30 01:20:26,426 DEBUG : BROWSER_OUTPUT: RSS: Main: 275644416
01:20:26 INFO - 2015-10-30 01:20:26,426 DEBUG : BROWSER_OUTPUT:
01:20:27 INFO - 2015-10-30 01:20:27,114 DEBUG : BROWSER_OUTPUT: Cycle 1(5): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:27 INFO - 2015-10-30 01:20:27,710 DEBUG : BROWSER_OUTPUT: RSS: Main: 275419136
01:20:27 INFO - 2015-10-30 01:20:27,710 DEBUG : BROWSER_OUTPUT:
01:20:28 INFO - 2015-10-30 01:20:28,409 DEBUG : BROWSER_OUTPUT: Cycle 1(6): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:29 INFO - 2015-10-30 01:20:29,001 DEBUG : BROWSER_OUTPUT: RSS: Main: 275460096
01:20:29 INFO - 2015-10-30 01:20:29,001 DEBUG : BROWSER_OUTPUT:
01:20:29 INFO - 2015-10-30 01:20:29,732 DEBUG : BROWSER_OUTPUT: Cycle 1(7): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:30 INFO - 2015-10-30 01:20:30,330 DEBUG : BROWSER_OUTPUT: RSS: Main: 275443712
01:20:30 INFO - 2015-10-30 01:20:30,330 DEBUG : BROWSER_OUTPUT:
01:20:31 INFO - 2015-10-30 01:20:31,053 DEBUG : BROWSER_OUTPUT: Cycle 1(8): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:31 INFO - 2015-10-30 01:20:31,656 DEBUG : BROWSER_OUTPUT: RSS: Main: 274997248
01:20:31 INFO - 2015-10-30 01:20:31,656 DEBUG : BROWSER_OUTPUT:
01:20:32 INFO - 2015-10-30 01:20:32,377 DEBUG : BROWSER_OUTPUT: Cycle 1(9): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:32 INFO - 2015-10-30 01:20:32,973 DEBUG : BROWSER_OUTPUT: RSS: Main: 274767872
01:20:32 INFO - 2015-10-30 01:20:32,974 DEBUG : BROWSER_OUTPUT:
01:20:33 INFO - 2015-10-30 01:20:33,660 DEBUG : BROWSER_OUTPUT: Cycle 1(10): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:34 INFO - 2015-10-30 01:20:34,268 DEBUG : BROWSER_OUTPUT: RSS: Main: 270028800
01:20:34 INFO - 2015-10-30 01:20:34,268 DEBUG : BROWSER_OUTPUT:
01:20:34 INFO - 2015-10-30 01:20:34,991 DEBUG : BROWSER_OUTPUT: Cycle 1(11): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:35 INFO - 2015-10-30 01:20:35,583 DEBUG : BROWSER_OUTPUT: RSS: Main: 269664256
01:20:35 INFO - 2015-10-30 01:20:35,584 DEBUG : BROWSER_OUTPUT:
01:20:36 INFO - 2015-10-30 01:20:36,313 DEBUG : BROWSER_OUTPUT: Cycle 1(12): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:36 INFO - 2015-10-30 01:20:36,908 DEBUG : BROWSER_OUTPUT: RSS: Main: 270516224
01:20:36 INFO - 2015-10-30 01:20:36,909 DEBUG : BROWSER_OUTPUT:
01:20:37 INFO - 2015-10-30 01:20:37,601 DEBUG : BROWSER_OUTPUT: Cycle 1(13): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:38 INFO - 2015-10-30 01:20:38,201 DEBUG : BROWSER_OUTPUT: RSS: Main: 270544896
01:20:38 INFO - 2015-10-30 01:20:38,201 DEBUG : BROWSER_OUTPUT:
01:20:38 INFO - 2015-10-30 01:20:38,925 DEBUG : BROWSER_OUTPUT: Cycle 1(14): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:39 INFO - 2015-10-30 01:20:39,525 DEBUG : BROWSER_OUTPUT: RSS: Main: 270614528
01:20:39 INFO - 2015-10-30 01:20:39,525 DEBUG : BROWSER_OUTPUT:
01:20:40 INFO - 2015-10-30 01:20:40,248 DEBUG : BROWSER_OUTPUT: Cycle 1(15): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:40 INFO - 2015-10-30 01:20:40,848 DEBUG : BROWSER_OUTPUT: RSS: Main: 270327808
01:20:40 INFO - 2015-10-30 01:20:40,848 DEBUG : BROWSER_OUTPUT:
01:20:41 INFO - 2015-10-30 01:20:41,554 DEBUG : BROWSER_OUTPUT: Cycle 1(16): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:42 INFO - 2015-10-30 01:20:42,156 DEBUG : BROWSER_OUTPUT: RSS: Main: 270606336
01:20:42 INFO - 2015-10-30 01:20:42,156 DEBUG : BROWSER_OUTPUT:
01:20:42 INFO - 2015-10-30 01:20:42,879 DEBUG : BROWSER_OUTPUT: Cycle 1(17): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:43 INFO - 2015-10-30 01:20:43,481 DEBUG : BROWSER_OUTPUT: RSS: Main: 269565952
01:20:43 INFO - 2015-10-30 01:20:43,481 DEBUG : BROWSER_OUTPUT:
01:20:44 INFO - 2015-10-30 01:20:44,205 DEBUG : BROWSER_OUTPUT: Cycle 1(18): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:44 INFO - 2015-10-30 01:20:44,808 DEBUG : BROWSER_OUTPUT: RSS: Main: 269316096
01:20:44 INFO - 2015-10-30 01:20:44,808 DEBUG : BROWSER_OUTPUT:
01:20:45 INFO - 2015-10-30 01:20:45,528 DEBUG : BROWSER_OUTPUT: Cycle 1(19): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:46 INFO - 2015-10-30 01:20:46,133 DEBUG : BROWSER_OUTPUT: RSS: Main: 269316096
01:20:46 INFO - 2015-10-30 01:20:46,133 DEBUG : BROWSER_OUTPUT:
01:20:46 INFO - 2015-10-30 01:20:46,858 DEBUG : BROWSER_OUTPUT: Cycle 1(20): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:47 INFO - 2015-10-30 01:20:47,453 DEBUG : BROWSER_OUTPUT: RSS: Main: 269172736
01:20:47 INFO - 2015-10-30 01:20:47,453 DEBUG : BROWSER_OUTPUT:
01:20:48 INFO - 2015-10-30 01:20:48,155 DEBUG : BROWSER_OUTPUT: Cycle 1(21): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:48 INFO - 2015-10-30 01:20:48,757 DEBUG : BROWSER_OUTPUT: RSS: Main: 268025856
01:20:48 INFO - 2015-10-30 01:20:48,758 DEBUG : BROWSER_OUTPUT:
01:20:49 INFO - 2015-10-30 01:20:49,468 DEBUG : BROWSER_OUTPUT: Cycle 1(22): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:50 INFO - 2015-10-30 01:20:50,071 DEBUG : BROWSER_OUTPUT: RSS: Main: 269193216
01:20:50 INFO - 2015-10-30 01:20:50,071 DEBUG : BROWSER_OUTPUT:
01:20:50 INFO - 2015-10-30 01:20:50,759 DEBUG : BROWSER_OUTPUT: Cycle 1(23): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:51 INFO - 2015-10-30 01:20:51,350 DEBUG : BROWSER_OUTPUT: RSS: Main: 269381632
01:20:51 INFO - 2015-10-30 01:20:51,350 DEBUG : BROWSER_OUTPUT:
01:20:52 INFO - 2015-10-30 01:20:52,079 DEBUG : BROWSER_OUTPUT: Cycle 1(24): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:52 INFO - 2015-10-30 01:20:52,685 DEBUG : BROWSER_OUTPUT: RSS: Main: 268267520
01:20:52 INFO - 2015-10-30 01:20:52,685 DEBUG : BROWSER_OUTPUT:
01:20:53 INFO - 2015-10-30 01:20:53,409 DEBUG : BROWSER_OUTPUT: Cycle 1(25): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:53 INFO - 2015-10-30 01:20:53,667 DEBUG : BROWSER_OUTPUT: RSS: Main: 275505152
01:20:53 INFO - 2015-10-30 01:20:53,667 DEBUG : BROWSER_OUTPUT:
01:20:53 INFO - 2015-10-30 01:20:53,667 DEBUG : BROWSER_OUTPUT: __start_tp_report
01:20:53 INFO - 2015-10-30 01:20:53,667 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load
01:20:53 INFO - 2015-10-30 01:20:53,667 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load_details
01:20:53 INFO - 2015-10-30 01:20:53,667 DEBUG : BROWSER_OUTPUT: |i|pagename|runs|
01:20:53 INFO - 2015-10-30 01:20:53,667 DEBUG : BROWSER_OUTPUT: |0;dhtml.html;1044;1215;1217;1221;1205;1228;1223;1258;1235;1223;1110;1222;1254;1215;1138;1142;1110;1214;1211;1259;1217;1137;1213;1212;1224
01:20:53 INFO - 2015-10-30 01:20:53,668 DEBUG : BROWSER_OUTPUT: |1;tablemutation.html;272;274;268;273;262;266;261;264;261;264;262;263;264;264;261;268;260;263;260;261;271;257;262;262;261
01:20:53 INFO - 2015-10-30 01:20:53,668 DEBUG : BROWSER_OUTPUT: __end_tp_report
01:20:53 INFO - 2015-10-30 01:20:53,668 DEBUG : BROWSER_OUTPUT: __start_cc_report
01:20:53 INFO - 2015-10-30 01:20:53,668 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_cycle_collect,6211
01:20:53 INFO - 2015-10-30 01:20:53,668 DEBUG : BROWSER_OUTPUT: __end_cc_report
01:20:53 INFO - 2015-10-30 01:20:53,668 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193253660__endTimestamp
01:20:53 INFO - 2015-10-30 01:20:53,668 DEBUG : BROWSER_OUTPUT:
01:20:53 INFO - 2015-10-30 01:20:53,668 DEBUG : BROWSER_OUTPUT: ------- Summary: start -------
01:20:53 INFO - 2015-10-30 01:20:53,669 DEBUG : BROWSER_OUTPUT: Number of tests: 2
01:20:53 INFO - 2015-10-30 01:20:53,669 DEBUG : BROWSER_OUTPUT:
01:20:53 INFO - 2015-10-30 01:20:53,669 DEBUG : BROWSER_OUTPUT: [#0] dhtml.html Cycles:25 Average:1197.88 Median:1215.00 stddev:53.08 (4.4%) stddev-sans-first:43.21
01:20:53 INFO - 2015-10-30 01:20:53,669 DEBUG : BROWSER_OUTPUT: Values: 1044.0 1215.0 1217.0 1221.0 1205.0 1228.0 1223.0 1258.0 1235.0 1223.0 1110.0 1222.0 1254.0 1215.0 1138.0 1142.0 1110.0 1214.0 1211.0 1259.0 1217.0 1137.0 1213.0 1212.0 1224.0
01:20:53 INFO - 2015-10-30 01:20:53,669 DEBUG : BROWSER_OUTPUT:
01:20:53 INFO - 2015-10-30 01:20:53,669 DEBUG : BROWSER_OUTPUT: [#1] tablemutation.html Cycles:25 Average:264.16 Median:263.00 stddev:4.44 (1.7%) stddev-sans-first:4.22
01:20:53 INFO - 2015-10-30 01:20:53,669 DEBUG : BROWSER_OUTPUT: Values: 272.0 274.0 268.0 273.0 262.0 266.0 261.0 264.0 261.0 264.0 262.0 263.0 264.0 264.0 261.0 268.0 260.0 263.0 260.0 261.0 271.0 257.0 262.0 262.0 261.0
01:20:53 INFO - 2015-10-30 01:20:53,670 DEBUG : BROWSER_OUTPUT: -------- Summary: end --------
01:20:53 INFO - 2015-10-30 01:20:53,670 DEBUG : BROWSER_OUTPUT:
01:20:54 INFO - 2015-10-30 01:20:54,192 INFO : Browser exited with error code: 0
01:20:54 INFO - 2015-10-30 01:20:54,215 INFO : Completed test a11yr (00:01:38)
01:20:54 INFO - 2015-10-30 01:20:54,215 INFO : Starting test ts_paint
01:20:54 INFO - 2015-10-30 01:20:54,215 DEBUG : operating with platform_type : mac_
01:20:54 INFO - 2015-10-30 01:20:54,215 INFO : Initialising browser for ts_paint test...
01:20:54 INFO - 2015-10-30 01:20:54,230 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/getInfo.html
01:20:56 INFO - 2015-10-30 01:20:56,532 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
01:20:56 INFO - 2015-10-30 01:20:56,533 DEBUG : BROWSER_OUTPUT: colorDepth:24
01:20:56 INFO - 2015-10-30 01:20:56,533 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/689
01:20:56 INFO - 2015-10-30 01:20:56,533 DEBUG : BROWSER_OUTPUT: __metrics
01:20:56 INFO - 2015-10-30 01:20:56,549 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]
01:20:57 INFO - 2015-10-30 01:20:57,251 INFO : Browser initialized.
01:20:57 INFO - 2015-10-30 01:20:57,251 INFO : Running cycle 1/20 for ts_paint test...
01:20:57 INFO - 2015-10-30 01:20:57,251 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html
01:20:59 INFO - 2015-10-30 01:20:59,076 DEBUG : BROWSER_OUTPUT: __start_report1819__end_report
01:20:59 INFO - 2015-10-30 01:20:59,076 DEBUG : BROWSER_OUTPUT:
01:20:59 INFO - 2015-10-30 01:20:59,085 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193259084__endTimestamp
01:20:59 INFO - 2015-10-30 01:20:59,752 INFO : Browser exited with error code: 0
01:20:59 INFO - 2015-10-30 01:20:59,754 INFO : Running cycle 2/20 for ts_paint test...
01:20:59 INFO - 2015-10-30 01:20:59,754 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html
01:21:01 INFO - 2015-10-30 01:21:01,060 DEBUG : BROWSER_OUTPUT: __start_report1304__end_report
01:21:01 INFO - 2015-10-30 01:21:01,060 DEBUG : BROWSER_OUTPUT:
01:21:01 INFO - 2015-10-30 01:21:01,077 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193261070__endTimestamp
01:21:01 INFO - 2015-10-30 01:21:01,708 INFO : Browser exited with error code: 0
01:21:01 INFO - 2015-10-30 01:21:01,710 INFO : Running cycle 3/20 for ts_paint test...
01:21:01 INFO - 2015-10-30 01:21:01,710 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html
01:21:03 INFO - 2015-10-30 01:21:03,029 DEBUG : BROWSER_OUTPUT: __start_report1316__end_report
01:21:03 INFO - 2015-10-30 01:21:03,030 DEBUG : BROWSER_OUTPUT:
01:21:03 INFO - 2015-10-30 01:21:03,045 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193263039__endTimestamp
01:21:03 INFO - 2015-10-30 01:21:03,669 INFO : Browser exited with error code: 0
01:21:03 INFO - 2015-10-30 01:21:03,671 INFO : Running cycle 4/20 for ts_paint test...
01:21:03 INFO - 2015-10-30 01:21:03,671 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html
01:21:05 INFO - 2015-10-30 01:21:05,015 DEBUG : BROWSER_OUTPUT: __start_report1342__end_report
01:21:05 INFO - 2015-10-30 01:21:05,015 DEBUG : BROWSER_OUTPUT:
01:21:05 INFO - 2015-10-30 01:21:05,023 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193265022__endTimestamp
01:21:05 INFO - 2015-10-30 01:21:05,677 INFO : Browser exited with error code: 0
01:21:05 INFO - 2015-10-30 01:21:05,678 INFO : Running cycle 5/20 for ts_paint test...
01:21:05 INFO - 2015-10-30 01:21:05,678 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html
01:21:07 INFO - 2015-10-30 01:21:07,020 DEBUG : BROWSER_OUTPUT: __start_report1334__end_report
01:21:07 INFO - 2015-10-30 01:21:07,020 DEBUG : BROWSER_OUTPUT:
01:21:07 INFO - 2015-10-30 01:21:07,024 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193267022__endTimestamp
01:21:07 INFO - 2015-10-30 01:21:07,726 INFO : Browser exited with error code: 0
01:21:07 INFO - 2015-10-30 01:21:07,728 INFO : Running cycle 6/20 for ts_paint test...
01:21:07 INFO - 2015-10-30 01:21:07,728 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html
01:21:09 INFO - 2015-10-30 01:21:09,071 DEBUG : BROWSER_OUTPUT: __start_report1334__end_report
01:21:09 INFO - 2015-10-30 01:21:09,071 DEBUG : BROWSER_OUTPUT:
01:21:09 INFO - 2015-10-30 01:21:09,079 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193269076__endTimestamp
01:21:09 INFO - 2015-10-30 01:21:09,768 INFO : Browser exited with error code: 0
01:21:09 INFO - 2015-10-30 01:21:09,769 INFO : Running cycle 7/20 for ts_paint test...
01:21:09 INFO - 2015-10-30 01:21:09,769 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html
01:21:11 INFO - 2015-10-30 01:21:11,089 DEBUG : BROWSER_OUTPUT: __start_report1309__end_report
01:21:11 INFO - 2015-10-30 01:21:11,089 DEBUG : BROWSER_OUTPUT:
01:21:11 INFO - 2015-10-30 01:21:11,096 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193271096__endTimestamp
01:21:11 INFO - 2015-10-30 01:21:11,787 INFO : Browser exited with error code: 0
01:21:11 INFO - 2015-10-30 01:21:11,788 INFO : Running cycle 8/20 for ts_paint test...
01:21:11 INFO - 2015-10-30 01:21:11,789 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html
01:21:13 INFO - 2015-10-30 01:21:13,118 DEBUG : BROWSER_OUTPUT: __start_report1324__end_report
01:21:13 INFO - 2015-10-30 01:21:13,118 DEBUG : BROWSER_OUTPUT:
01:21:13 INFO - 2015-10-30 01:21:13,125 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193273122__endTimestamp
01:21:13 INFO - 2015-10-30 01:21:13,828 INFO : Browser exited with error code: 0
01:21:13 INFO - 2015-10-30 01:21:13,829 INFO : Running cycle 9/20 for ts_paint test...
01:21:13 INFO - 2015-10-30 01:21:13,829 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html
01:21:15 INFO - 2015-10-30 01:21:15,145 DEBUG : BROWSER_OUTPUT: __start_report1313__end_report
01:21:15 INFO - 2015-10-30 01:21:15,145 DEBUG : BROWSER_OUTPUT:
01:21:15 INFO - 2015-10-30 01:21:15,161 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193275155__endTimestamp
01:21:15 INFO - 2015-10-30 01:21:15,897 INFO : Browser exited with error code: 0
01:21:15 INFO - 2015-10-30 01:21:15,898 INFO : Running cycle 10/20 for ts_paint test...
01:21:15 INFO - 2015-10-30 01:21:15,898 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html
01:21:17 INFO - 2015-10-30 01:21:17,221 DEBUG : BROWSER_OUTPUT: __start_report1314__end_report
01:21:17 INFO - 2015-10-30 01:21:17,221 DEBUG : BROWSER_OUTPUT:
01:21:17 INFO - 2015-10-30 01:21:17,223 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193277222__endTimestamp
01:21:17 INFO - 2015-10-30 01:21:17,926 INFO : Browser exited with error code: 0
01:21:17 INFO - 2015-10-30 01:21:17,928 INFO : Running cycle 11/20 for ts_paint test...
01:21:17 INFO - 2015-10-30 01:21:17,928 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html
01:21:19 INFO - 2015-10-30 01:21:19,252 DEBUG : BROWSER_OUTPUT: __start_report1319__end_report
01:21:19 INFO - 2015-10-30 01:21:19,253 DEBUG : BROWSER_OUTPUT:
01:21:19 INFO - 2015-10-30 01:21:19,260 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193279258__endTimestamp
01:21:19 INFO - 2015-10-30 01:21:19,983 INFO : Browser exited with error code: 0
01:21:19 INFO - 2015-10-30 01:21:19,985 INFO : Running cycle 12/20 for ts_paint test...
01:21:19 INFO - 2015-10-30 01:21:19,985 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html
01:21:21 INFO - 2015-10-30 01:21:21,317 DEBUG : BROWSER_OUTPUT: __start_report1327__end_report
01:21:21 INFO - 2015-10-30 01:21:21,317 DEBUG : BROWSER_OUTPUT:
01:21:21 INFO - 2015-10-30 01:21:21,326 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193281323__endTimestamp
01:21:22 INFO - 2015-10-30 01:21:22,043 INFO : Browser exited with error code: 0
01:21:22 INFO - 2015-10-30 01:21:22,045 INFO : Running cycle 13/20 for ts_paint test...
01:21:22 INFO - 2015-10-30 01:21:22,045 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html
01:21:23 INFO - 2015-10-30 01:21:23,351 DEBUG : BROWSER_OUTPUT: __start_report1302__end_report
01:21:23 INFO - 2015-10-30 01:21:23,351 DEBUG : BROWSER_OUTPUT:
01:21:23 INFO - 2015-10-30 01:21:23,361 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193283356__endTimestamp
01:21:24 INFO - 2015-10-30 01:21:24,066 INFO : Browser exited with error code: 0
01:21:24 INFO - 2015-10-30 01:21:24,068 INFO : Running cycle 14/20 for ts_paint test...
01:21:24 INFO - 2015-10-30 01:21:24,068 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html
01:21:25 INFO - 2015-10-30 01:21:25,399 DEBUG : BROWSER_OUTPUT: __start_report1322__end_report
01:21:25 INFO - 2015-10-30 01:21:25,399 DEBUG : BROWSER_OUTPUT:
01:21:25 INFO - 2015-10-30 01:21:25,402 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193285402__endTimestamp
01:21:26 INFO - 2015-10-30 01:21:26,143 INFO : Browser exited with error code: 0
01:21:26 INFO - 2015-10-30 01:21:26,145 INFO : Running cycle 15/20 for ts_paint test...
01:21:26 INFO - 2015-10-30 01:21:26,145 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html
01:21:27 INFO - 2015-10-30 01:21:27,467 DEBUG : BROWSER_OUTPUT: __start_report1315__end_report
01:21:27 INFO - 2015-10-30 01:21:27,467 DEBUG : BROWSER_OUTPUT:
01:21:27 INFO - 2015-10-30 01:21:27,475 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193287472__endTimestamp
01:21:28 INFO - 2015-10-30 01:21:28,218 INFO : Browser exited with error code: 0
01:21:28 INFO - 2015-10-30 01:21:28,219 INFO : Running cycle 16/20 for ts_paint test...
01:21:28 INFO - 2015-10-30 01:21:28,219 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html
01:21:29 INFO - 2015-10-30 01:21:29,535 DEBUG : BROWSER_OUTPUT: __start_report1307__end_report
01:21:29 INFO - 2015-10-30 01:21:29,535 DEBUG : BROWSER_OUTPUT:
01:21:29 INFO - 2015-10-30 01:21:29,539 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193289538__endTimestamp
01:21:30 INFO - 2015-10-30 01:21:30,259 INFO : Browser exited with error code: 0
01:21:30 INFO - 2015-10-30 01:21:30,261 INFO : Running cycle 17/20 for ts_paint test...
01:21:30 INFO - 2015-10-30 01:21:30,261 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html
01:21:31 INFO - 2015-10-30 01:21:31,583 DEBUG : BROWSER_OUTPUT: __start_report1317__end_report
01:21:31 INFO - 2015-10-30 01:21:31,583 DEBUG : BROWSER_OUTPUT:
01:21:31 INFO - 2015-10-30 01:21:31,601 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193291590__endTimestamp
01:21:32 INFO - 2015-10-30 01:21:32,363 INFO : Browser exited with error code: 0
01:21:32 INFO - 2015-10-30 01:21:32,364 INFO : Running cycle 18/20 for ts_paint test...
01:21:32 INFO - 2015-10-30 01:21:32,364 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html
01:21:33 INFO - 2015-10-30 01:21:33,680 DEBUG : BROWSER_OUTPUT: __start_report1312__end_report
01:21:33 INFO - 2015-10-30 01:21:33,680 DEBUG : BROWSER_OUTPUT:
01:21:33 INFO - 2015-10-30 01:21:33,699 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193293688__endTimestamp
01:21:34 INFO - 2015-10-30 01:21:34,519 INFO : Browser exited with error code: 0
01:21:34 INFO - 2015-10-30 01:21:34,520 INFO : Running cycle 19/20 for ts_paint test...
01:21:34 INFO - 2015-10-30 01:21:34,521 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html
01:21:35 INFO - 2015-10-30 01:21:35,850 DEBUG : BROWSER_OUTPUT: __start_report1327__end_report
01:21:35 INFO - 2015-10-30 01:21:35,850 DEBUG : BROWSER_OUTPUT:
01:21:35 INFO - 2015-10-30 01:21:35,858 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193295857__endTimestamp
01:21:36 INFO - 2015-10-30 01:21:36,572 INFO : Browser exited with error code: 0
01:21:36 INFO - 2015-10-30 01:21:36,573 INFO : Running cycle 20/20 for ts_paint test...
01:21:36 INFO - 2015-10-30 01:21:36,573 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html
01:21:37 INFO - 2015-10-30 01:21:37,876 DEBUG : BROWSER_OUTPUT: __start_report1299__end_report
01:21:37 INFO - 2015-10-30 01:21:37,876 DEBUG : BROWSER_OUTPUT:
01:21:37 INFO - 2015-10-30 01:21:37,894 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193297887__endTimestamp
01:21:38 INFO - 2015-10-30 01:21:38,602 INFO : Browser exited with error code: 0
01:21:38 INFO - 2015-10-30 01:21:38,629 INFO : Completed test ts_paint (00:00:44)
01:21:38 INFO - 2015-10-30 01:21:38,629 INFO : Starting test tpaint
01:21:38 INFO - 2015-10-30 01:21:38,630 DEBUG : operating with platform_type : mac_
01:21:38 INFO - 2015-10-30 01:21:38,630 INFO : Initialising browser for tpaint test...
01:21:38 INFO - 2015-10-30 01:21:38,643 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpKkln0C/profile http://localhost/getInfo.html
01:21:41 INFO - 2015-10-30 01:21:41,236 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
01:21:41 INFO - 2015-10-30 01:21:41,236 DEBUG : BROWSER_OUTPUT: colorDepth:24
01:21:41 INFO - 2015-10-30 01:21:41,236 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/689
01:21:41 INFO - 2015-10-30 01:21:41,236 DEBUG : BROWSER_OUTPUT: __metrics
01:21:41 INFO - 2015-10-30 01:21:41,252 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]
01:21:41 INFO - 2015-10-30 01:21:41,937 INFO : Browser initialized.
01:21:41 INFO - 2015-10-30 01:21:41,938 INFO : Running cycle 1/1 for tpaint test...
01:21:41 INFO - 2015-10-30 01:21:41,938 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpKkln0C/profile file:///builds/slave/test/build/tests/talos/talos/startup_test/tpaint.html?auto=1
01:22:10 INFO - 2015-10-30 01:22:10,353 DEBUG : BROWSER_OUTPUT: __start_report291.4549999999999|298.97500000000036|300.6700000000001|304.2699999999995|307.1900000000005|307.90999999999985|308.10499999999956|309.0750000000007|310.4949999999999|312.15999999999985|313.3250000000007|314.4549999999999|314.96500000000015|316.1750000000029|318.28499999999985|333.8199999999997|336.7400000000016|385.89500000000044|396.2999999999993|482.619999999999__end_report__startTimestamp1446193330350__endTimestamp
01:22:10 INFO - 2015-10-30 01:22:10,354 DEBUG : BROWSER_OUTPUT: openingTimes=298.97500000000036,300.6700000000001,304.2699999999995,307.1900000000005,307.90999999999985,308.10499999999956,309.0750000000007,310.4949999999999,312.15999999999985,313.3250000000007,314.4549999999999,314.96500000000015,316.1750000000029,318.28499999999985,333.8199999999997,336.7400000000016,385.89500000000044,396.2999999999993,482.619999999999
01:22:10 INFO - 2015-10-30 01:22:10,354 DEBUG : BROWSER_OUTPUT: avgOpenTime:328.14
01:22:10 INFO - 2015-10-30 01:22:10,354 DEBUG : BROWSER_OUTPUT: minOpenTime:291.45
01:22:10 INFO - 2015-10-30 01:22:10,354 DEBUG : BROWSER_OUTPUT: maxOpenTime:482.62
01:22:10 INFO - 2015-10-30 01:22:10,354 DEBUG : BROWSER_OUTPUT: medOpenTime:312.7425000000003
01:22:10 INFO - 2015-10-30 01:22:10,354 DEBUG : BROWSER_OUTPUT: __xulWinOpenTime:312.7425000000003
01:22:11 INFO - 2015-10-30 01:22:11,110 INFO : Browser exited with error code: 0
01:22:11 INFO - 2015-10-30 01:22:11,130 INFO : Completed test tpaint (00:00:32)
01:22:11 INFO - 2015-10-30 01:22:11,131 INFO : Starting test sessionrestore
01:22:11 INFO - 2015-10-30 01:22:11,131 DEBUG : operating with platform_type : mac_
01:22:11 INFO - 2015-10-30 01:22:11,131 INFO : Initialising browser for sessionrestore test...
01:22:11 INFO - 2015-10-30 01:22:11,149 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile http://localhost/getInfo.html
01:22:13 INFO - 2015-10-30 01:22:13,558 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
01:22:13 INFO - 2015-10-30 01:22:13,558 DEBUG : BROWSER_OUTPUT: colorDepth:24
01:22:13 INFO - 2015-10-30 01:22:13,559 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1200/743
01:22:13 INFO - 2015-10-30 01:22:13,559 DEBUG : BROWSER_OUTPUT: __metrics
01:22:13 INFO - 2015-10-30 01:22:13,575 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]
01:22:14 INFO - 2015-10-30 01:22:14,346 INFO : Browser initialized.
01:22:14 INFO - 2015-10-30 01:22:14,347 INFO : Running cycle 1/10 for sessionrestore test...
01:22:14 INFO - 2015-10-30 01:22:14,347 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile/sessionstore.js
01:22:14 INFO - 2015-10-30 01:22:14,352 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile http://localhost/startup_test/sessionrestore/index.html
01:22:19 INFO - 2015-10-30 01:22:19,373 DEBUG : BROWSER_OUTPUT: __start_report2641__end_report
01:22:19 INFO - 2015-10-30 01:22:19,373 DEBUG : BROWSER_OUTPUT:
01:22:19 INFO - 2015-10-30 01:22:19,373 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193339369__endTimestamp
01:22:19 INFO - 2015-10-30 01:22:19,373 DEBUG : BROWSER_OUTPUT:
01:22:20 INFO - 2015-10-30 01:22:20,656 INFO : Browser exited with error code: 0
01:22:20 INFO - 2015-10-30 01:22:20,658 INFO : Running cycle 2/10 for sessionrestore test...
01:22:20 INFO - 2015-10-30 01:22:20,658 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile/sessionstore.js
01:22:20 INFO - 2015-10-30 01:22:20,664 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile http://localhost/startup_test/sessionrestore/index.html
01:22:24 INFO - 2015-10-30 01:22:24,509 DEBUG : BROWSER_OUTPUT: __start_report2309__end_report
01:22:24 INFO - 2015-10-30 01:22:24,509 DEBUG : BROWSER_OUTPUT:
01:22:24 INFO - 2015-10-30 01:22:24,509 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193344508__endTimestamp
01:22:24 INFO - 2015-10-30 01:22:24,509 DEBUG : BROWSER_OUTPUT:
01:22:26 INFO - 2015-10-30 01:22:26,053 INFO : Browser exited with error code: 0
01:22:26 INFO - 2015-10-30 01:22:26,055 INFO : Running cycle 3/10 for sessionrestore test...
01:22:26 INFO - 2015-10-30 01:22:26,055 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile/sessionstore.js
01:22:26 INFO - 2015-10-30 01:22:26,060 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile http://localhost/startup_test/sessionrestore/index.html
01:22:29 INFO - 2015-10-30 01:22:29,906 DEBUG : BROWSER_OUTPUT: __start_report2317__end_report
01:22:29 INFO - 2015-10-30 01:22:29,906 DEBUG : BROWSER_OUTPUT:
01:22:29 INFO - 2015-10-30 01:22:29,906 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193349905__endTimestamp
01:22:29 INFO - 2015-10-30 01:22:29,906 DEBUG : BROWSER_OUTPUT:
01:22:31 INFO - 2015-10-30 01:22:31,464 INFO : Browser exited with error code: 0
01:22:31 INFO - 2015-10-30 01:22:31,465 INFO : Running cycle 4/10 for sessionrestore test...
01:22:31 INFO - 2015-10-30 01:22:31,465 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile/sessionstore.js
01:22:31 INFO - 2015-10-30 01:22:31,471 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile http://localhost/startup_test/sessionrestore/index.html
01:22:35 INFO - 2015-10-30 01:22:35,327 DEBUG : BROWSER_OUTPUT: __start_report2307__end_report
01:22:35 INFO - 2015-10-30 01:22:35,328 DEBUG : BROWSER_OUTPUT:
01:22:35 INFO - 2015-10-30 01:22:35,328 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193355326__endTimestamp
01:22:35 INFO - 2015-10-30 01:22:35,328 DEBUG : BROWSER_OUTPUT:
01:22:36 INFO - 2015-10-30 01:22:36,945 INFO : Browser exited with error code: 0
01:22:36 INFO - 2015-10-30 01:22:36,947 INFO : Running cycle 5/10 for sessionrestore test...
01:22:36 INFO - 2015-10-30 01:22:36,947 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile/sessionstore.js
01:22:36 INFO - 2015-10-30 01:22:36,952 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile http://localhost/startup_test/sessionrestore/index.html
01:22:40 INFO - 2015-10-30 01:22:40,811 DEBUG : BROWSER_OUTPUT: __start_report2317__end_report
01:22:40 INFO - 2015-10-30 01:22:40,811 DEBUG : BROWSER_OUTPUT:
01:22:40 INFO - 2015-10-30 01:22:40,811 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193360809__endTimestamp
01:22:40 INFO - 2015-10-30 01:22:40,812 DEBUG : BROWSER_OUTPUT:
01:22:42 INFO - 2015-10-30 01:22:42,465 INFO : Browser exited with error code: 0
01:22:42 INFO - 2015-10-30 01:22:42,467 INFO : Running cycle 6/10 for sessionrestore test...
01:22:42 INFO - 2015-10-30 01:22:42,467 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile/sessionstore.js
01:22:42 INFO - 2015-10-30 01:22:42,472 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile http://localhost/startup_test/sessionrestore/index.html
01:22:46 INFO - 2015-10-30 01:22:46,318 DEBUG : BROWSER_OUTPUT: __start_report2318__end_report
01:22:46 INFO - 2015-10-30 01:22:46,319 DEBUG : BROWSER_OUTPUT:
01:22:46 INFO - 2015-10-30 01:22:46,319 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193366316__endTimestamp
01:22:46 INFO - 2015-10-30 01:22:46,319 DEBUG : BROWSER_OUTPUT:
01:22:47 INFO - 2015-10-30 01:22:47,965 INFO : Browser exited with error code: 0
01:22:47 INFO - 2015-10-30 01:22:47,966 INFO : Running cycle 7/10 for sessionrestore test...
01:22:47 INFO - 2015-10-30 01:22:47,966 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile/sessionstore.js
01:22:47 INFO - 2015-10-30 01:22:47,972 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile http://localhost/startup_test/sessionrestore/index.html
01:22:51 INFO - 2015-10-30 01:22:51,819 DEBUG : BROWSER_OUTPUT: __start_report2308__end_report
01:22:51 INFO - 2015-10-30 01:22:51,819 DEBUG : BROWSER_OUTPUT:
01:22:51 INFO - 2015-10-30 01:22:51,819 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193371817__endTimestamp
01:22:51 INFO - 2015-10-30 01:22:51,819 DEBUG : BROWSER_OUTPUT:
01:22:53 INFO - 2015-10-30 01:22:53,464 INFO : Browser exited with error code: 0
01:22:53 INFO - 2015-10-30 01:22:53,465 INFO : Running cycle 8/10 for sessionrestore test...
01:22:53 INFO - 2015-10-30 01:22:53,465 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile/sessionstore.js
01:22:53 INFO - 2015-10-30 01:22:53,471 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile http://localhost/startup_test/sessionrestore/index.html
01:22:57 INFO - 2015-10-30 01:22:57,314 DEBUG : BROWSER_OUTPUT: __start_report2319__end_report
01:22:57 INFO - 2015-10-30 01:22:57,315 DEBUG : BROWSER_OUTPUT:
01:22:57 INFO - 2015-10-30 01:22:57,315 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193377311__endTimestamp
01:22:57 INFO - 2015-10-30 01:22:57,315 DEBUG : BROWSER_OUTPUT:
01:22:58 INFO - 2015-10-30 01:22:58,947 INFO : Browser exited with error code: 0
01:22:58 INFO - 2015-10-30 01:22:58,948 INFO : Running cycle 9/10 for sessionrestore test...
01:22:58 INFO - 2015-10-30 01:22:58,949 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile/sessionstore.js
01:22:58 INFO - 2015-10-30 01:22:58,954 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile http://localhost/startup_test/sessionrestore/index.html
01:23:02 INFO - 2015-10-30 01:23:02,803 DEBUG : BROWSER_OUTPUT: __start_report2310__end_report
01:23:02 INFO - 2015-10-30 01:23:02,803 DEBUG : BROWSER_OUTPUT:
01:23:02 INFO - 2015-10-30 01:23:02,803 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193382802__endTimestamp
01:23:02 INFO - 2015-10-30 01:23:02,803 DEBUG : BROWSER_OUTPUT:
01:23:04 INFO - 2015-10-30 01:23:04,558 INFO : Browser exited with error code: 0
01:23:04 INFO - 2015-10-30 01:23:04,560 INFO : Running cycle 10/10 for sessionrestore test...
01:23:04 INFO - 2015-10-30 01:23:04,560 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile/sessionstore.js
01:23:04 INFO - 2015-10-30 01:23:04,565 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile http://localhost/startup_test/sessionrestore/index.html
01:23:08 INFO - 2015-10-30 01:23:08,389 DEBUG : BROWSER_OUTPUT: __start_report2303__end_report
01:23:08 INFO - 2015-10-30 01:23:08,389 DEBUG : BROWSER_OUTPUT:
01:23:08 INFO - 2015-10-30 01:23:08,390 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193388388__endTimestamp
01:23:08 INFO - 2015-10-30 01:23:08,390 DEBUG : BROWSER_OUTPUT:
01:23:10 INFO - 2015-10-30 01:23:10,056 INFO : Browser exited with error code: 0
01:23:10 INFO - 2015-10-30 01:23:10,079 INFO : Completed test sessionrestore (00:00:58)
01:23:10 INFO - 2015-10-30 01:23:10,079 INFO : Starting test sessionrestore_no_auto_restore
01:23:10 INFO - 2015-10-30 01:23:10,079 DEBUG : operating with platform_type : mac_
01:23:10 INFO - 2015-10-30 01:23:10,080 INFO : Initialising browser for sessionrestore_no_auto_restore test...
01:23:10 INFO - 2015-10-30 01:23:10,100 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile http://localhost/getInfo.html
01:23:12 INFO - 2015-10-30 01:23:12,697 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
01:23:12 INFO - 2015-10-30 01:23:12,698 DEBUG : BROWSER_OUTPUT: colorDepth:24
01:23:12 INFO - 2015-10-30 01:23:12,698 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1200/743
01:23:12 INFO - 2015-10-30 01:23:12,698 DEBUG : BROWSER_OUTPUT: __metrics
01:23:12 INFO - 2015-10-30 01:23:12,714 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]
01:23:13 INFO - 2015-10-30 01:23:13,498 INFO : Browser initialized.
01:23:13 INFO - 2015-10-30 01:23:13,499 INFO : Running cycle 1/10 for sessionrestore_no_auto_restore test...
01:23:13 INFO - 2015-10-30 01:23:13,499 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile/sessionstore.js
01:23:13 INFO - 2015-10-30 01:23:13,505 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile http://localhost/startup_test/sessionrestore/index.html
01:23:15 INFO - 2015-10-30 01:23:15,358 DEBUG : BROWSER_OUTPUT: __start_report1313__end_report
01:23:15 INFO - 2015-10-30 01:23:15,358 DEBUG : BROWSER_OUTPUT:
01:23:15 INFO - 2015-10-30 01:23:15,358 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193395355__endTimestamp
01:23:15 INFO - 2015-10-30 01:23:15,358 DEBUG : BROWSER_OUTPUT:
01:23:16 INFO - 2015-10-30 01:23:16,004 INFO : Browser exited with error code: 0
01:23:16 INFO - 2015-10-30 01:23:16,006 INFO : Running cycle 2/10 for sessionrestore_no_auto_restore test...
01:23:16 INFO - 2015-10-30 01:23:16,006 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile/sessionstore.js
01:23:16 INFO - 2015-10-30 01:23:16,029 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile http://localhost/startup_test/sessionrestore/index.html
01:23:17 INFO - 2015-10-30 01:23:17,476 DEBUG : BROWSER_OUTPUT: __start_report1014__end_report
01:23:17 INFO - 2015-10-30 01:23:17,476 DEBUG : BROWSER_OUTPUT:
01:23:17 INFO - 2015-10-30 01:23:17,476 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193397473__endTimestamp
01:23:17 INFO - 2015-10-30 01:23:17,476 DEBUG : BROWSER_OUTPUT:
01:23:18 INFO - 2015-10-30 01:23:18,114 INFO : Browser exited with error code: 0
01:23:18 INFO - 2015-10-30 01:23:18,116 INFO : Running cycle 3/10 for sessionrestore_no_auto_restore test...
01:23:18 INFO - 2015-10-30 01:23:18,116 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile/sessionstore.js
01:23:18 INFO - 2015-10-30 01:23:18,122 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile http://localhost/startup_test/sessionrestore/index.html
01:23:19 INFO - 2015-10-30 01:23:19,571 DEBUG : BROWSER_OUTPUT: __start_report1016__end_report
01:23:19 INFO - 2015-10-30 01:23:19,571 DEBUG : BROWSER_OUTPUT:
01:23:19 INFO - 2015-10-30 01:23:19,572 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193399571__endTimestamp
01:23:19 INFO - 2015-10-30 01:23:19,572 DEBUG : BROWSER_OUTPUT:
01:23:20 INFO - 2015-10-30 01:23:20,227 INFO : Browser exited with error code: 0
01:23:20 INFO - 2015-10-30 01:23:20,229 INFO : Running cycle 4/10 for sessionrestore_no_auto_restore test...
01:23:20 INFO - 2015-10-30 01:23:20,229 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile/sessionstore.js
01:23:20 INFO - 2015-10-30 01:23:20,235 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile http://localhost/startup_test/sessionrestore/index.html
01:23:21 INFO - 2015-10-30 01:23:21,681 DEBUG : BROWSER_OUTPUT: __start_report1001__end_report
01:23:21 INFO - 2015-10-30 01:23:21,681 DEBUG : BROWSER_OUTPUT:
01:23:21 INFO - 2015-10-30 01:23:21,682 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193401680__endTimestamp
01:23:21 INFO - 2015-10-30 01:23:21,682 DEBUG : BROWSER_OUTPUT:
01:23:22 INFO - 2015-10-30 01:23:22,401 INFO : Browser exited with error code: 0
01:23:22 INFO - 2015-10-30 01:23:22,402 INFO : Running cycle 5/10 for sessionrestore_no_auto_restore test...
01:23:22 INFO - 2015-10-30 01:23:22,402 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile/sessionstore.js
01:23:22 INFO - 2015-10-30 01:23:22,407 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile http://localhost/startup_test/sessionrestore/index.html
01:23:23 INFO - 2015-10-30 01:23:23,860 DEBUG : BROWSER_OUTPUT: __start_report1007__end_report
01:23:23 INFO - 2015-10-30 01:23:23,860 DEBUG : BROWSER_OUTPUT:
01:23:23 INFO - 2015-10-30 01:23:23,860 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193403857__endTimestamp
01:23:23 INFO - 2015-10-30 01:23:23,860 DEBUG : BROWSER_OUTPUT:
01:23:24 INFO - 2015-10-30 01:23:24,598 INFO : Browser exited with error code: 0
01:23:24 INFO - 2015-10-30 01:23:24,599 INFO : Running cycle 6/10 for sessionrestore_no_auto_restore test...
01:23:24 INFO - 2015-10-30 01:23:24,600 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile/sessionstore.js
01:23:24 INFO - 2015-10-30 01:23:24,605 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile http://localhost/startup_test/sessionrestore/index.html
01:23:26 INFO - 2015-10-30 01:23:26,060 DEBUG : BROWSER_OUTPUT: __start_report1010__end_report
01:23:26 INFO - 2015-10-30 01:23:26,060 DEBUG : BROWSER_OUTPUT:
01:23:26 INFO - 2015-10-30 01:23:26,060 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193406059__endTimestamp
01:23:26 INFO - 2015-10-30 01:23:26,060 DEBUG : BROWSER_OUTPUT:
01:23:26 INFO - 2015-10-30 01:23:26,815 INFO : Browser exited with error code: 0
01:23:26 INFO - 2015-10-30 01:23:26,817 INFO : Running cycle 7/10 for sessionrestore_no_auto_restore test...
01:23:26 INFO - 2015-10-30 01:23:26,817 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile/sessionstore.js
01:23:26 INFO - 2015-10-30 01:23:26,823 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile http://localhost/startup_test/sessionrestore/index.html
01:23:28 INFO - 2015-10-30 01:23:28,253 DEBUG : BROWSER_OUTPUT: __start_report997__end_report
01:23:28 INFO - 2015-10-30 01:23:28,253 DEBUG : BROWSER_OUTPUT:
01:23:28 INFO - 2015-10-30 01:23:28,253 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193408252__endTimestamp
01:23:28 INFO - 2015-10-30 01:23:28,253 DEBUG : BROWSER_OUTPUT:
01:23:29 INFO - 2015-10-30 01:23:29,015 INFO : Browser exited with error code: 0
01:23:29 INFO - 2015-10-30 01:23:29,018 INFO : Running cycle 8/10 for sessionrestore_no_auto_restore test...
01:23:29 INFO - 2015-10-30 01:23:29,018 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile/sessionstore.js
01:23:29 INFO - 2015-10-30 01:23:29,023 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile http://localhost/startup_test/sessionrestore/index.html
01:23:30 INFO - 2015-10-30 01:23:30,470 DEBUG : BROWSER_OUTPUT: __start_report1013__end_report
01:23:30 INFO - 2015-10-30 01:23:30,470 DEBUG : BROWSER_OUTPUT:
01:23:30 INFO - 2015-10-30 01:23:30,470 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193410468__endTimestamp
01:23:30 INFO - 2015-10-30 01:23:30,470 DEBUG : BROWSER_OUTPUT:
01:23:31 INFO - 2015-10-30 01:23:31,226 INFO : Browser exited with error code: 0
01:23:31 INFO - 2015-10-30 01:23:31,227 INFO : Running cycle 9/10 for sessionrestore_no_auto_restore test...
01:23:31 INFO - 2015-10-30 01:23:31,228 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile/sessionstore.js
01:23:31 INFO - 2015-10-30 01:23:31,234 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile http://localhost/startup_test/sessionrestore/index.html
01:23:32 INFO - 2015-10-30 01:23:32,675 DEBUG : BROWSER_OUTPUT: __start_report1007__end_report
01:23:32 INFO - 2015-10-30 01:23:32,675 DEBUG : BROWSER_OUTPUT:
01:23:32 INFO - 2015-10-30 01:23:32,675 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193412671__endTimestamp
01:23:32 INFO - 2015-10-30 01:23:32,676 DEBUG : BROWSER_OUTPUT:
01:23:33 INFO - 2015-10-30 01:23:33,455 INFO : Browser exited with error code: 0
01:23:33 INFO - 2015-10-30 01:23:33,457 INFO : Running cycle 10/10 for sessionrestore_no_auto_restore test...
01:23:33 INFO - 2015-10-30 01:23:33,457 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile/sessionstore.js
01:23:33 INFO - 2015-10-30 01:23:33,463 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile http://localhost/startup_test/sessionrestore/index.html
01:23:34 INFO - 2015-10-30 01:23:34,905 DEBUG : BROWSER_OUTPUT: __start_report1007__end_report
01:23:34 INFO - 2015-10-30 01:23:34,906 DEBUG : BROWSER_OUTPUT:
01:23:34 INFO - 2015-10-30 01:23:34,906 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193414897__endTimestamp
01:23:34 INFO - 2015-10-30 01:23:34,906 DEBUG : BROWSER_OUTPUT:
01:23:35 INFO - 2015-10-30 01:23:35,664 INFO : Browser exited with error code: 0
01:23:35 INFO - 2015-10-30 01:23:35,687 INFO : Completed test sessionrestore_no_auto_restore (00:00:25)
01:23:35 INFO - 2015-10-30 01:23:35,687 INFO : Completed test suite (00:04:19)
01:23:35 INFO - 2015-10-30 01:23:35,687 DEBUG : Working with test: a11yr
01:23:35 INFO - 2015-10-30 01:23:35,687 DEBUG : Generating results file: a11yr
01:23:35 INFO - 2015-10-30 01:23:35,687 DEBUG : Working with test: ts_paint
01:23:35 INFO - 2015-10-30 01:23:35,688 DEBUG : Generating results file: ts_paint
01:23:35 INFO - 2015-10-30 01:23:35,688 DEBUG : Working with test: tpaint
01:23:35 INFO - 2015-10-30 01:23:35,689 DEBUG : Generating results file: tpaint
01:23:35 INFO - 2015-10-30 01:23:35,689 DEBUG : Working with test: sessionrestore
01:23:35 INFO - 2015-10-30 01:23:35,689 DEBUG : Generating results file: sessionrestore
01:23:35 INFO - 2015-10-30 01:23:35,689 DEBUG : Working with test: sessionrestore_no_auto_restore
01:23:35 INFO - 2015-10-30 01:23:35,689 DEBUG : Generating results file: sessionrestore_no_auto_restore
01:23:35 INFO - 2015-10-30 01:23:35,690 INFO : Posting result 0 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
01:23:35 INFO - 2015-10-30 01:23:35,741 DEBUG : process_Request line: a11yr_paint graph.html#tests=[[223,52,55]]
01:23:35 INFO - 2015-10-30 01:23:35,741 DEBUG : process_Request line: a11yr_paint 565.29 graph.html#tests=[[223,52,55]]
01:23:35 INFO - 2015-10-30 01:23:35,741 INFO : Posting result 1 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
01:23:35 INFO - 2015-10-30 01:23:35,803 DEBUG : process_Request line: ts_paint graph.html#tests=[[83,52,55]]
01:23:35 INFO - 2015-10-30 01:23:35,803 DEBUG : process_Request line: ts_paint 1339.10 graph.html#tests=[[83,52,55]]
01:23:35 INFO - 2015-10-30 01:23:35,803 INFO : Posting result 2 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
01:23:35 INFO - 2015-10-30 01:23:35,837 DEBUG : process_Request line: tpaint graph.html#tests=[[82,52,55]]
01:23:35 INFO - 2015-10-30 01:23:35,837 DEBUG : process_Request line: tpaint 314.97 graph.html#tests=[[82,52,55]]
01:23:35 INFO - 2015-10-30 01:23:35,837 INFO : Posting result 3 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
01:23:35 INFO - 2015-10-30 01:23:35,891 DEBUG : process_Request line: sessionrestore graph.html#tests=[[313,52,55]]
01:23:35 INFO - 2015-10-30 01:23:35,891 DEBUG : process_Request line: sessionrestore 2342.96 graph.html#tests=[[313,52,55]]
01:23:35 INFO - 2015-10-30 01:23:35,892 INFO : Posting result 4 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
01:23:35 INFO - 2015-10-30 01:23:35,943 DEBUG : process_Request line: sessionrestore_no_auto_restore graph.html#tests=[[315,52,55]]
01:23:35 INFO - 2015-10-30 01:23:35,943 DEBUG : process_Request line: sessionrestore_no_auto_restore 1034.99 graph.html#tests=[[315,52,55]]
01:23:35 INFO - 2015-10-30 01:23:35,944 INFO : TALOSDATA: [{"talos_counters": {}, "results": {"dhtml.html": [1044.0, 1215.0, 1217.0, 1221.0, 1205.0, 1228.0, 1223.0, 1258.0, 1235.0, 1223.0, 1110.0, 1222.0, 1254.0, 1215.0, 1138.0, 1142.0, 1110.0, 1214.0, 1211.0, 1259.0, 1217.0, 1137.0, 1213.0, 1212.0, 1224.0], "tablemutation.html": [272.0, 274.0, 268.0, 273.0, 262.0, 266.0, 261.0, 264.0, 261.0, 264.0, 262.0, 263.0, 264.0, 264.0, 261.0, 268.0, 260.0, 263.0, 260.0, 261.0, 271.0, 257.0, 262.0, 262.0, 261.0]}, "summary": {"suite": 565.2857052760558, "subtests": {"dhtml.html": {"std": 42.30196918846949, "min": 1110.0, "max": 1259.0, "median": 1216.0, "filtered": 1216.0, "mean": 1204.2916666666667}, "tablemutation.html": {"std": 4.129837231121288, "min": 257.0, "max": 274.0, "median": 262.5, "filtered": 262.5, "mean": 263.8333333333333}}}, "test_machine": {"platform": "x86_64", "osversion": "OS X 10.10.2", "os": "mac", "name": "t-yosemite-r5-0025"}, "testrun": {"date": 1446193156, "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": "43.0a2", "id": "20151029014646", "branch": "Mozilla-Aurora", "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797"}}, {"talos_counters": {}, "results": {"ts_paint": [1819.0, 1304.0, 1316.0, 1342.0, 1334.0, 1334.0, 1309.0, 1324.0, 1313.0, 1314.0, 1319.0, 1327.0, 1302.0, 1322.0, 1315.0, 1307.0, 1317.0, 1312.0, 1327.0, 1299.0]}, "summary": {"suite": 1316.0, "subtests": {"ts_paint": {"std": 11.257007666633626, "min": 1299.0, "max": 1342.0, "median": 1316.0, "filtered": 1316.0, "mean": 1317.7368421052631}}}, "test_machine": {"platform": "x86_64", "osversion": "OS X 10.10.2", "os": "mac", "name": "t-yosemite-r5-0025"}, "testrun": {"date": 1446193156, "suite": "ts_paint", "options": {"responsiveness": false, "cycles": 20, "tpmozafterpaint": true, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "43.0a2", "id": "20151029014646", "branch": "Mozilla-Aurora", "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797"}}, {"talos_counters": {}, "results": {"tpaint": [291.4549999999999, 298.97500000000036, 300.6700000000001, 304.2699999999995, 307.1900000000005, 307.90999999999985, 308.10499999999956, 309.0750000000007, 310.4949999999999, 312.15999999999985, 313.3250000000007, 314.4549999999999, 314.96500000000015, 316.1750000000029, 318.28499999999985, 333.8199999999997, 336.7400000000016, 385.89500000000044, 396.2999999999993, 482.619999999999]}, "summary": {"suite": 314.96500000000015, "subtests": {"tpaint": {"std": 47.07400992054924, "min": 307.90999999999985, "max": 482.619999999999, "median": 314.96500000000015, "filtered": 314.96500000000015, "mean": 337.35500000000025}}}, "test_machine": {"platform": "x86_64", "osversion": "OS X 10.10.2", "os": "mac", "name": "t-yosemite-r5-0025"}, "testrun": {"date": 1446193156, "suite": "tpaint", "options": {"responsiveness": false, "cycles": 1, "tpmozafterpaint": true, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "43.0a2", "id": "20151029014646", "branch": "Mozilla-Aurora", "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797"}}, {"talos_counters": {}, "results": {"sessionrestore": [2641.0, 2309.0, 2317.0, 2307.0, 2317.0, 2318.0, 2308.0, 2319.0, 2310.0, 2303.0]}, "summary": {"suite": 2310.0, "subtests": {"sessionrestore": {"std": 5.477225575051661, "min": 2303.0, "max": 2319.0, "median": 2310.0, "filtered": 2310.0, "mean": 2312.0}}}, "test_machine": {"platform": "x86_64", "osversion": "OS X 10.10.2", "os": "mac", "name": "t-yosemite-r5-0025"}, "testrun": {"date": 1446193156, "suite": "sessionrestore", "options": {"responsiveness": false, "cycles": 10, "tpmozafterpaint": false, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "43.0a2", "id": "20151029014646", "branch": "Mozilla-Aurora", "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797"}}, {"talos_counters": {}, "results": {"sessionrestore_no_auto_restore": [1313.0, 1014.0, 1016.0, 1001.0, 1007.0, 1010.0, 997.0, 1013.0, 1007.0, 1007.0]}, "summary": {"suite": 1007.0, "subtests": {"sessionrestore_no_auto_restore": {"std": 5.792715732327589, "min": 997.0, "max": 1016.0, "median": 1007.0, "filtered": 1007.0, "mean": 1008.0}}}, "test_machine": {"platform": "x86_64", "osversion": "OS X 10.10.2", "os": "mac", "name": "t-yosemite-r5-0025"}, "testrun": {"date": 1446193156, "suite": "sessionrestore_no_auto_restore", "options": {"responsiveness": false, "cycles": 10, "tpmozafterpaint": false, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "43.0a2", "id": "20151029014646", "branch": "Mozilla-Aurora", "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797"}}]
01:23:35 INFO - RETURN: a11yr_paint: 565.29
01:23:35 INFO - RETURN: ts_paint: 1339.10
01:23:35 INFO - RETURN: tpaint: 314.97
01:23:35 INFO - RETURN: sessionrestore: 2342.96
01:23:35 INFO - RETURN: sessionrestore_no_auto_restore: 1034.99
01:23:35 INFO - TinderboxPrint: TalosResult: {"graphserver": {"sessionrestore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[313,52,55]]", "result": "2342.96"}, "a11yr_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[223,52,55]]", "result": "565.29"}, "tpaint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[82,52,55]]", "result": "314.97"}, "ts_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[83,52,55]]", "result": "1339.10"}, "sessionrestore_no_auto_restore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[315,52,55]]", "result": "1034.99"}}}
01:23:35 INFO - Return code: 0
01:23:35 INFO - # TBPL SUCCESS #
01:23:35 INFO - Running pre test command check_screen_resolution with 'bash -c screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'
01:23:35 INFO - Running command: ['bash', '-c', 'screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'] in /builds/slave/test/build
01:23:35 INFO - Copy/paste: bash -c "screenresolution get && screenresolution list && system_profiler SPDisplaysDataType"
01:23:35 INFO - 2015-10-30 01:23:35.990 screenresolution[1687:12661] starting screenresolution argv=screenresolution get
01:23:35 INFO - 2015-10-30 01:23:35.993 screenresolution[1687:12661] Display 0: 1600x1200x32@60
01:23:36 INFO - 2015-10-30 01:23:35.999 screenresolution[1688:12663] starting screenresolution argv=screenresolution list
01:23:36 INFO - Available Modes on Display 0
01:23:36 INFO - 1600x1200x32@60 1152x870x32@75 1280x1024x32@75
01:23:36 INFO - 1024x768x32@75 1024x768x32@70 1024x768x32@60
01:23:36 INFO - 800x600x32@75 800x600x32@60 640x480x32@75
01:23:36 INFO - 640x480x32@60 1280x1024x32@60 1280x960x32@60
01:23:36 INFO - 1280x960x32@75 1344x1008x32@60 Graphics/Displays:
01:23:36 INFO - Intel HD Graphics 3000:
01:23:36 INFO - Chipset Model: Intel HD Graphics 3000
01:23:36 INFO - Type: GPU
01:23:36 INFO - Bus: Built-In
01:23:36 INFO - VRAM (Total): 512 MB
01:23:36 INFO - VRAM (Dynamic, Max): 10
01:23:36 INFO - Vendor: Intel (0x8086)
01:23:36 INFO - Device ID: 0x0116
01:23:36 INFO - Revision ID: 0x0009
01:23:36 INFO - Displays:
01:23:36 INFO - Display:
01:23:36 INFO - Resolution: 1600 x 1200 @ 60 Hz
01:23:36 INFO - Pixel Depth: 32-Bit Color (ARGB8888)
01:23:36 INFO - Display Serial Number: 1600x1200 60
01:23:36 INFO - Main Display: Yes
01:23:36 INFO - Mirror: Off
01:23:36 INFO - Online: Yes
01:23:36 INFO - Rotation: Supported
01:23:36 INFO - Return code: 0
01:23:36 INFO - Running post-action listener: _resource_record_post_action
01:23:36 INFO - Running post-run listener: _resource_record_post_run
01:23:37 INFO - Total resource usage - Wall time: 298s; CPU: 29.0%; Read bytes: 39330816; Write bytes: 584681472; Read time: 4212; Write time: 33755
01:23:37 INFO - install - Wall time: 39s; CPU: 30.0%; Read bytes: 330840576; Write bytes: 324933632; Read time: 33946; Write time: 14436
01:23:37 INFO - run-tests - Wall time: 261s; CPU: 29.0%; Read bytes: 37143552; Write bytes: 246747136; Read time: 3846; Write time: 18556
01:23:37 INFO - Running post-run listener: _upload_blobber_files
01:23:37 INFO - Blob upload gear active.
01:23:37 INFO - There are no files to upload in the directory. Skipping the blob upload mechanism ...
01:23:37 INFO - Copying logs to upload dir...
01:23:37 INFO - mkdir: /builds/slave/test/build/upload/logs
program finished with exit code 0
elapsedTime=365.083027
========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 6 mins, 6 secs) (at 2015-10-30 01:23:39.198862) =========
========= Started set props: build_url (results: 0, elapsed: 0 secs) (at 2015-10-30 01:23:39.202847) =========
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.GdR3T8lx2O/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.Xo8SBI494k/Listeners
TMPDIR=/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.dmg
program finished with exit code 0
elapsedTime=0.010013
build_url: 'https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.dmg'
========= Finished set props: build_url (results: 0, elapsed: 0 secs) (at 2015-10-30 01:23:39.260152) =========
========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:23:39.260467) =========
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.GdR3T8lx2O/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.Xo8SBI494k/Listeners
TMPDIR=/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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.005375
========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:23:39.310274) =========
========= Started reboot slave lost (results: 0, elapsed: 7 secs) (at 2015-10-30 01:23:39.310593) =========
========= Finished reboot slave lost (results: 0, elapsed: 7 secs) (at 2015-10-30 01:23:46.357961) =========