builder: mozilla-aurora_ubuntu64_hw_test-other-pgo
slave: talos-linux64-ix-041
starttime: 1446193090.68
results: success (0)
buildid: 20151029014646
builduid: e2197d6fa76745edba8eadefeb37f684
revision: 41fdefd640f368bccdeafe6446d42c0a5ad22797
========= Started set props: master (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:10.675718) =========
master: http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/
========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:10.676147) =========
========= Started set props: basedir (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:10.676432) =========
bash -c pwd
in dir /builds/slave/test-pgo/. (timeout 1200 secs)
watching logfiles {}
argv: ['bash', '-c', 'pwd']
environment:
DISPLAY=:0
HOME=/home/cltbld
LANG=en_US.UTF-8
LANGUAGE=en_US:en
LOGNAME=cltbld
MAIL=/var/mail/cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript
NO_EM_RESTART=1
PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
PWD=/builds/slave/test-pgo
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
/builds/slave/test-pgo
program finished with exit code 0
elapsedTime=0.005712
basedir: '/builds/slave/test-pgo'
========= Finished set props: basedir (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:10.775541) =========
========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:10.775825) =========
========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:10.817992) =========
========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:10.818340) =========
rm -rf properties
in dir /builds/slave/test-pgo/. (timeout 1200 secs)
watching logfiles {}
argv: ['rm', '-rf', 'properties']
environment:
DISPLAY=:0
HOME=/home/cltbld
LANG=en_US.UTF-8
LANGUAGE=en_US:en
LOGNAME=cltbld
MAIL=/var/mail/cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript
NO_EM_RESTART=1
PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
PWD=/builds/slave/test-pgo
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
program finished with exit code 0
elapsedTime=0.027882
========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:10.865602) =========
========= Started set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:10.865889) =========
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:18:10.866250) =========
========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:10.866543) =========
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-pgo/. (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:
DISPLAY=:0
HOME=/home/cltbld
LANG=en_US.UTF-8
LANGUAGE=en_US:en
LOGNAME=cltbld
MAIL=/var/mail/cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript
NO_EM_RESTART=1
PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
PWD=/builds/slave/test-pgo
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
--2015-10-30 01:18:11-- https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py
Resolving hg.mozilla.org (hg.mozilla.org)... 63.245.215.25, 63.245.215.102
Connecting to hg.mozilla.org (hg.mozilla.org)|63.245.215.25|:443... connected.
HTTP request sent, awaiting response... 200 Script output follows
Length: 12141 (12K) [text/x-python]
Saving to: `archiver_client.py'
0K .......... . 100% 227M=0s
2015-10-30 01:18:11 (227 MB/s) - `archiver_client.py' saved [12141/12141]
program finished with exit code 0
elapsedTime=0.191593
========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:11.070638) =========
========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:11.070966) =========
rm -rf scripts
in dir /builds/slave/test-pgo/. (timeout 1200 secs)
watching logfiles {}
argv: ['rm', '-rf', 'scripts']
environment:
DISPLAY=:0
HOME=/home/cltbld
LANG=en_US.UTF-8
LANGUAGE=en_US:en
LOGNAME=cltbld
MAIL=/var/mail/cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript
NO_EM_RESTART=1
PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
PWD=/builds/slave/test-pgo
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
program finished with exit code 0
elapsedTime=0.195883
========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:11.278285) =========
========= Started 'bash -c ...' (results: 0, elapsed: 1 secs) (at 2015-10-30 01:18:11.278641) =========
bash -c 'python archiver_client.py mozharness --repo releases/mozilla-aurora --rev 41fdefd640f368bccdeafe6446d42c0a5ad22797 --destination scripts --debug'
in dir /builds/slave/test-pgo/. (timeout 1200 secs)
watching logfiles {}
argv: ['bash', '-c', u'python archiver_client.py mozharness --repo releases/mozilla-aurora --rev 41fdefd640f368bccdeafe6446d42c0a5ad22797 --destination scripts --debug']
environment:
DISPLAY=:0
HOME=/home/cltbld
LANG=en_US.UTF-8
LANGUAGE=en_US:en
LOGNAME=cltbld
MAIL=/var/mail/cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript
NO_EM_RESTART=1
PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
PWD=/builds/slave/test-pgo
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
2015-10-30 01:18:11,399 truncating revision to first 12 chars
2015-10-30 01:18:11,399 Setting DEBUG logging.
2015-10-30 01:18:11,399 attempt 1/10
2015-10-30 01:18:11,399 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:18:12,430 unpacking tar archive at: mozilla-aurora-41fdefd640f3/testing/mozharness/
program finished with exit code 0
elapsedTime=1.306379
========= Finished 'bash -c ...' (results: 0, elapsed: 1 secs) (at 2015-10-30 01:18:12.597094) =========
========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:12.597386) =========
========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:12.605226) =========
========= Started tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:12.605494) =========
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:18:12.605863) =========
========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 5 mins, 7 secs) (at 2015-10-30 01:18:12.606161) =========
/tools/buildbot/bin/python scripts/scripts/talos_script.py --suite other --add-option --webServer,localhost --branch-name Mozilla-Aurora --system-bits 64 --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Mozilla-Aurora
in dir /builds/slave/test-pgo/. (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/linux_config.py', '--download-symbols', 'ondemand', '--use-talos-json', '--blob-upload-branch', 'Mozilla-Aurora']
environment:
DISPLAY=:0
HOME=/home/cltbld
LANG=en_US.UTF-8
LANGUAGE=en_US:en
LOGNAME=cltbld
MAIL=/var/mail/cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript
NO_EM_RESTART=1
PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
PROPERTIES_FILE=/builds/slave/test-pgo/buildprops.json
PWD=/builds/slave/test-pgo
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
01:18:12 INFO - MultiFileLogger online at 20151030 01:18:12 in /builds/slave/test-pgo
01:18:12 INFO - Run as scripts/scripts/talos_script.py --suite other --add-option --webServer,localhost --branch-name Mozilla-Aurora --system-bits 64 --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Mozilla-Aurora
01:18:12 INFO - Guessing talos json url...
01:18:12 INFO - Using buildbot properties:
01:18:12 INFO - {
01:18:12 INFO - "properties": {
01:18:12 INFO - "buildnumber": 12,
01:18:12 INFO - "product": "firefox",
01:18:12 INFO - "script_repo_revision": "production",
01:18:12 INFO - "builddir": "mozilla-aurora_ubuntu64_hw_test-other",
01:18:12 INFO - "repository": "",
01:18:12 INFO - "buildername": "Ubuntu HW 12.04 x64 mozilla-aurora pgo talos other",
01:18:12 INFO - "buildid": "20151029014646",
01:18:12 INFO - "slavename": "talos-linux64-ix-041",
01:18:12 INFO - "pgo_build": "True",
01:18:12 INFO - "basedir": "/builds/slave/test-pgo",
01:18:12 INFO - "project": "",
01:18:12 INFO - "platform": "ubuntu64_hw",
01:18:12 INFO - "master": "http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/",
01:18:12 INFO - "slavebuilddir": "test",
01:18:12 INFO - "scheduler": "tests-mozilla-aurora-linux64-pgo-talos",
01:18:12 INFO - "branch": "mozilla-aurora",
01:18:12 INFO - "repo_path": "releases/mozilla-aurora",
01:18:12 INFO - "stage_platform": "linux64-pgo",
01:18:12 INFO - "builduid": "e2197d6fa76745edba8eadefeb37f684",
01:18:12 INFO - "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797"
01:18:12 INFO - },
01:18:12 INFO - "sourcestamp": {
01:18:12 INFO - "repository": "",
01:18:12 INFO - "hasPatch": false,
01:18:12 INFO - "project": "",
01:18:12 INFO - "branch": "mozilla-aurora-linux64-pgo-talos",
01:18:12 INFO - "changes": [
01:18:12 INFO - {
01:18:12 INFO - "category": null,
01:18:12 INFO - "files": [
01:18:12 INFO - {
01:18:12 INFO - "url": null,
01:18:12 INFO - "name": "https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2"
01:18:12 INFO - }
01:18:12 INFO - ],
01:18:12 INFO - "repository": "",
01:18:12 INFO - "rev": "41fdefd640f368bccdeafe6446d42c0a5ad22797",
01:18:12 INFO - "who": "jyavenard@mozilla.com",
01:18:12 INFO - "when": 1446116590,
01:18:12 INFO - "number": 6592947,
01:18:12 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:18:12 INFO - "project": "",
01:18:12 INFO - "at": "Thu 29 Oct 2015 04:03:10",
01:18:12 INFO - "branch": "mozilla-aurora-linux64-pgo-talos",
01:18:12 INFO - "revlink": "",
01:18:12 INFO - "properties": [
01:18:12 INFO - [
01:18:12 INFO - "buildid",
01:18:12 INFO - "20151029014646",
01:18:12 INFO - "Change"
01:18:12 INFO - ],
01:18:12 INFO - [
01:18:12 INFO - "builduid",
01:18:12 INFO - "e2197d6fa76745edba8eadefeb37f684",
01:18:12 INFO - "Change"
01:18:12 INFO - ],
01:18:12 INFO - [
01:18:12 INFO - "pgo_build",
01:18:12 INFO - "True",
01:18:12 INFO - "Change"
01:18:12 INFO - ]
01:18:12 INFO - ],
01:18:12 INFO - "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797"
01:18:12 INFO - }
01:18:12 INFO - ],
01:18:12 INFO - "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797"
01:18:12 INFO - }
01:18:12 INFO - }
01:18:12 INFO - Found installer url https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2.
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 - https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.txt matches https://queue.taskcluster.net
01:18:12 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.txt
01:18:12 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.txt
01:18:12 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.txt to /builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.txt
01:18:12 INFO - retry: Calling _download_file with args: ('http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.txt', '/builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.txt'), kwargs: {}, attempt #1
01:18:23 INFO - Downloaded 107 bytes.
01:18:23 INFO - Reading from file /builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.txt
01:18:23 INFO - Contents:
01:18:23 INFO - 20151029014646
01:18:23 INFO - https://hg.mozilla.org/releases/mozilla-aurora/rev/41fdefd640f368bccdeafe6446d42c0a5ad22797
01:18:23 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
01:18:23 INFO - trying https://hg.mozilla.org/releases/mozilla-aurora/raw-file/41fdefd640/testing/talos/talos.json
01:18:23 INFO - Downloading https://hg.mozilla.org/releases/mozilla-aurora/raw-file/41fdefd640/testing/talos/talos.json to /builds/slave/test-pgo/build/talos.json
01:18:23 INFO - retry: Calling _download_file with args: ('https://hg.mozilla.org/releases/mozilla-aurora/raw-file/41fdefd640/testing/talos/talos.json', '/builds/slave/test-pgo/build/talos.json'), kwargs: {}, attempt #1
01:18:23 INFO - Downloaded 6818 bytes.
01:18:24 INFO - {'extra_options': {'android': ['--apkPath=%(apk_path)s']},
01:18:24 INFO - 'mobile-suites': {'remote-tp4m_nochrome': {'tests': ['tp4m']},
01:18:24 INFO - 'remote-trobocheck2': {'talos_options': ['--fennecIDs',
01:18:24 INFO - '../fennec_ids.txt'],
01:18:24 INFO - 'tests': ['tcheck2']},
01:18:24 INFO - 'remote-tsvgx': {'talos_options': ['--noChrome',
01:18:24 INFO - '--tppagecycles',
01:18:24 INFO - '7'],
01:18:24 INFO - 'tests': ['tsvgm']}},
01:18:24 INFO - 'suites': {'chromez': {'tests': ['tresize', 'tcanvasmark']},
01:18:24 INFO - 'chromez-e10s': {'talos_options': ['--e10s'],
01:18:24 INFO - 'tests': ['tresize', 'tcanvasmark']},
01:18:24 INFO - 'dromaeojs': {'tests': ['dromaeo_css', 'kraken', 'v8_7']},
01:18:24 INFO - 'dromaeojs-e10s': {'talos_options': ['--e10s'],
01:18:24 INFO - 'tests': ['dromaeo_css', 'kraken', 'v8_7']},
01:18:24 INFO - 'g1': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5o.manifest',
01:18:24 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/',
01:18:24 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
01:18:24 INFO - 'plugins': {'32': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash32_10_3_183_5.zip',
01:18:24 INFO - '64': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash64_11_0_d1_98.zip'},
01:18:24 INFO - 'tests': ['tp5o_scroll', 'glterrain']},
01:18:24 INFO - 'g1-e10s': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5o.manifest',
01:18:24 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/',
01:18:24 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
01:18:24 INFO - 'plugins': {'32': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash32_10_3_183_5.zip',
01:18:24 INFO - '64': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash64_11_0_d1_98.zip'},
01:18:24 INFO - 'talos_options': ['--e10s'],
01:18:24 INFO - 'tests': ['tp5o_scroll', 'glterrain']},
01:18:24 INFO - 'g2': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5o.manifest',
01:18:24 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/',
01:18:24 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
01:18:24 INFO - 'tests': ['damp', 'tps']},
01:18:24 INFO - 'g2-e10s': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5o.manifest',
01:18:24 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/',
01:18:24 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
01:18:24 INFO - 'talos_options': ['--e10s'],
01:18:24 INFO - 'tests': ['damp', 'tps']},
01:18:24 INFO - 'g3': {'tests': ['dromaeo_dom']},
01:18:24 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']},
01:18:24 INFO - 'other': {'tests': ['a11yr',
01:18:24 INFO - 'ts_paint',
01:18:24 INFO - 'tpaint',
01:18:24 INFO - 'sessionrestore',
01:18:24 INFO - 'sessionrestore_no_auto_restore']},
01:18:24 INFO - 'other-e10s': {'talos_options': ['--e10s'],
01:18:24 INFO - 'tests': ['a11yr',
01:18:24 INFO - 'ts_paint',
01:18:24 INFO - 'tpaint',
01:18:24 INFO - 'sessionrestore',
01:18:24 INFO - 'sessionrestore_no_auto_restore']},
01:18:24 INFO - 'other-e10s_l64': {'talos_options': ['--e10s'],
01:18:24 INFO - 'tests': ['a11yr',
01:18:24 INFO - 'ts_paint',
01:18:24 INFO - 'tpaint',
01:18:24 INFO - 'sessionrestore',
01:18:24 INFO - 'sessionrestore_no_auto_restore']},
01:18:24 INFO - 'other-e10s_nol64': {'talos_options': ['--e10s'],
01:18:24 INFO - 'tests': ['a11yr',
01:18:24 INFO - 'ts_paint',
01:18:24 INFO - 'tpaint',
01:18:24 INFO - 'sessionrestore',
01:18:24 INFO - 'sessionrestore_no_auto_restore']},
01:18:24 INFO - 'other_l64': {'tests': ['a11yr',
01:18:24 INFO - 'ts_paint',
01:18:24 INFO - 'tpaint',
01:18:24 INFO - 'sessionrestore',
01:18:24 INFO - 'sessionrestore_no_auto_restore']},
01:18:24 INFO - 'other_nol64': {'tests': ['a11yr',
01:18:24 INFO - 'ts_paint',
01:18:24 INFO - 'tpaint',
01:18:24 INFO - 'sessionrestore',
01:18:24 INFO - 'sessionrestore_no_auto_restore']},
01:18:24 INFO - 'svgr': {'tests': ['tsvgx',
01:18:24 INFO - 'tsvgr_opacity',
01:18:24 INFO - 'tart',
01:18:24 INFO - 'tscrollx',
01:18:24 INFO - 'cart']},
01:18:24 INFO - 'svgr-e10s': {'talos_options': ['--e10s'],
01:18:24 INFO - 'tests': ['tsvgx',
01:18:24 INFO - 'tsvgr_opacity',
01:18:24 INFO - 'tart',
01:18:24 INFO - 'tscrollx',
01:18:24 INFO - 'cart']},
01:18:24 INFO - 'tp5o': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5o.manifest',
01:18:24 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/',
01:18:24 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
01:18:24 INFO - 'plugins': {'32': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash32_10_3_183_5.zip',
01:18:24 INFO - '64': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash64_11_0_d1_98.zip'},
01:18:24 INFO - 'tests': ['tp5o']},
01:18:24 INFO - 'tp5o-e10s': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5o.manifest',
01:18:24 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/',
01:18:24 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
01:18:24 INFO - 'plugins': {'32': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash32_10_3_183_5.zip',
01:18:24 INFO - '64': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash64_11_0_d1_98.zip'},
01:18:24 INFO - 'talos_options': ['--e10s'],
01:18:24 INFO - 'tests': ['tp5o']},
01:18:24 INFO - 'xperf': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5n.manifest',
01:18:24 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/',
01:18:24 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
01:18:24 INFO - 'plugins': {'32': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash32_10_3_183_5.zip',
01:18:24 INFO - '64': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash64_11_0_d1_98.zip'},
01:18:24 INFO - 'talos_options': ['--xperf_path',
01:18:24 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'],
01:18:24 INFO - 'tests': ['tp5n']},
01:18:24 INFO - 'xperf-e10s': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5n.manifest',
01:18:24 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/',
01:18:24 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
01:18:24 INFO - 'plugins': {'32': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash32_10_3_183_5.zip',
01:18:24 INFO - '64': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash64_11_0_d1_98.zip'},
01:18:24 INFO - 'talos_options': ['--e10s',
01:18:24 INFO - '--xperf_path',
01:18:24 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"',
01:18:24 INFO - 'C:/slave/talos-data/talos/xperf.config'],
01:18:24 INFO - 'tests': ['tp5n']}},
01:18:24 INFO - 'talos.zip': {'path': '',
01:18:24 INFO - 'url': 'http://talos-bundles.pvt.build.mozilla.org/zips/talos.a6052c33d420.zip'}}
01:18:24 INFO - Dumping config to /builds/slave/test-pgo/logs/localconfig.json.
01:18:24 INFO - {'append_to_log': False,
01:18:24 INFO - 'base_work_dir': '/builds/slave/test-pgo',
01:18:24 INFO - 'blob_upload_branch': 'Mozilla-Aurora',
01:18:24 INFO - 'blob_uploader_auth_file': '/builds/slave/test-pgo/oauth.txt',
01:18:24 INFO - 'branch': 'Mozilla-Aurora',
01:18:24 INFO - 'buildbot_json_path': 'buildprops.json',
01:18:24 INFO - 'config_files': ('talos/linux_config.py',),
01:18:24 INFO - 'default_actions': ('clobber',
01:18:24 INFO - 'read-buildbot-config',
01:18:24 INFO - 'download-and-extract',
01:18:24 INFO - 'populate-webroot',
01:18:24 INFO - 'create-virtualenv',
01:18:24 INFO - 'install',
01:18:24 INFO - 'run-tests'),
01:18:24 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',),
01:18:24 INFO - 'download_minidump_stackwalk': True,
01:18:24 INFO - 'download_symbols': 'ondemand',
01:18:24 INFO - 'exes': {'python': '/tools/buildbot/bin/python',
01:18:24 INFO - 'tooltool.py': '/tools/tooltool.py',
01:18:24 INFO - 'virtualenv': ('/tools/buildbot/bin/python',
01:18:24 INFO - '/tools/misc-python/virtualenv.py')},
01:18:24 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub',
01:18:24 INFO - 'http://pypi.pub.build.mozilla.org/pub'),
01:18:24 INFO - 'installer_path': 'installer.exe',
01:18:24 INFO - 'log_level': 'info',
01:18:24 INFO - 'log_name': 'talos',
01:18:24 INFO - 'log_to_console': True,
01:18:24 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk',
01:18:24 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest',
01:18:24 INFO - 'opt_config_files': (),
01:18:24 INFO - 'pip_index': False,
01:18:24 INFO - 'python_webserver': False,
01:18:24 INFO - 'sps_profile': False,
01:18:24 INFO - 'sps_profile_interval': 0,
01:18:24 INFO - 'suite': 'other',
01:18:24 INFO - 'system_bits': '64',
01:18:24 INFO - 'talos_extra_options': ('--webServer', 'localhost'),
01:18:24 INFO - 'talos_url': 'https://hg.mozilla.org/build/talos/archive/tip.tar.gz',
01:18:24 INFO - 'tests': (),
01:18:24 INFO - 'title': 'talos-linux64-ix-041',
01:18:24 INFO - 'tooltool_cache': '/builds/tooltool_cache',
01:18:24 INFO - 'use_talos_json': True,
01:18:24 INFO - 'virtualenv_path': '/builds/slave/test-pgo/build/venv',
01:18:24 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None},
01:18:24 INFO - 'webroot': '/builds/slave/test-pgo/../talos-data',
01:18:24 INFO - 'work_dir': 'build'}
01:18:24 INFO - #####
01:18:24 INFO - ##### Running clobber step.
01:18:24 INFO - #####
01:18:24 INFO - Running pre-action listener: _resource_record_pre_action
01:18:24 INFO - Running main action method: clobber
01:18:24 INFO - rmtree: /builds/slave/test-pgo/build
01:18:24 INFO - retry: Calling rmtree with args: ('/builds/slave/test-pgo/build',), kwargs: {}, attempt #1
01:18:25 INFO - Running post-action listener: _resource_record_post_action
01:18:25 INFO - #####
01:18:25 INFO - ##### Running read-buildbot-config step.
01:18:25 INFO - #####
01:18:25 INFO - Running pre-action listener: _resource_record_pre_action
01:18:25 INFO - Running main action method: read_buildbot_config
01:18:25 INFO - Using buildbot properties:
01:18:25 INFO - {
01:18:25 INFO - "properties": {
01:18:25 INFO - "buildnumber": 12,
01:18:25 INFO - "product": "firefox",
01:18:25 INFO - "script_repo_revision": "production",
01:18:25 INFO - "builddir": "mozilla-aurora_ubuntu64_hw_test-other",
01:18:25 INFO - "repository": "",
01:18:25 INFO - "buildername": "Ubuntu HW 12.04 x64 mozilla-aurora pgo talos other",
01:18:25 INFO - "buildid": "20151029014646",
01:18:25 INFO - "slavename": "talos-linux64-ix-041",
01:18:25 INFO - "pgo_build": "True",
01:18:25 INFO - "basedir": "/builds/slave/test-pgo",
01:18:25 INFO - "project": "",
01:18:25 INFO - "platform": "ubuntu64_hw",
01:18:25 INFO - "master": "http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/",
01:18:25 INFO - "slavebuilddir": "test",
01:18:25 INFO - "scheduler": "tests-mozilla-aurora-linux64-pgo-talos",
01:18:25 INFO - "branch": "mozilla-aurora",
01:18:25 INFO - "repo_path": "releases/mozilla-aurora",
01:18:25 INFO - "stage_platform": "linux64-pgo",
01:18:25 INFO - "builduid": "e2197d6fa76745edba8eadefeb37f684",
01:18:25 INFO - "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797"
01:18:25 INFO - },
01:18:25 INFO - "sourcestamp": {
01:18:25 INFO - "repository": "",
01:18:25 INFO - "hasPatch": false,
01:18:25 INFO - "project": "",
01:18:25 INFO - "branch": "mozilla-aurora-linux64-pgo-talos",
01:18:25 INFO - "changes": [
01:18:25 INFO - {
01:18:25 INFO - "category": null,
01:18:25 INFO - "files": [
01:18:25 INFO - {
01:18:25 INFO - "url": null,
01:18:25 INFO - "name": "https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2"
01:18:25 INFO - }
01:18:25 INFO - ],
01:18:25 INFO - "repository": "",
01:18:25 INFO - "rev": "41fdefd640f368bccdeafe6446d42c0a5ad22797",
01:18:25 INFO - "who": "jyavenard@mozilla.com",
01:18:25 INFO - "when": 1446116590,
01:18:25 INFO - "number": 6592947,
01:18:25 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:18:25 INFO - "project": "",
01:18:25 INFO - "at": "Thu 29 Oct 2015 04:03:10",
01:18:25 INFO - "branch": "mozilla-aurora-linux64-pgo-talos",
01:18:25 INFO - "revlink": "",
01:18:25 INFO - "properties": [
01:18:25 INFO - [
01:18:25 INFO - "buildid",
01:18:25 INFO - "20151029014646",
01:18:25 INFO - "Change"
01:18:25 INFO - ],
01:18:25 INFO - [
01:18:25 INFO - "builduid",
01:18:25 INFO - "e2197d6fa76745edba8eadefeb37f684",
01:18:25 INFO - "Change"
01:18:25 INFO - ],
01:18:25 INFO - [
01:18:25 INFO - "pgo_build",
01:18:25 INFO - "True",
01:18:25 INFO - "Change"
01:18:25 INFO - ]
01:18:25 INFO - ],
01:18:25 INFO - "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797"
01:18:25 INFO - }
01:18:25 INFO - ],
01:18:25 INFO - "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797"
01:18:25 INFO - }
01:18:25 INFO - }
01:18:25 INFO - Running post-action listener: _resource_record_post_action
01:18:25 INFO - #####
01:18:25 INFO - ##### Running download-and-extract step.
01:18:25 INFO - #####
01:18:25 INFO - Running pre-action listener: _resource_record_pre_action
01:18:25 INFO - Running main action method: download_and_extract
01:18:25 INFO - mkdir: /builds/slave/test-pgo/build/tests
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 - https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/test_packages.json matches https://queue.taskcluster.net
01:18:25 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/test_packages.json
01:18:25 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/test_packages.json
01:18:25 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/test_packages.json to /builds/slave/test-pgo/build/test_packages.json
01:18:25 INFO - retry: Calling _download_file with args: ('http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/test_packages.json', '/builds/slave/test-pgo/build/test_packages.json'), kwargs: {}, attempt #1
01:18:26 INFO - Downloaded 1302 bytes.
01:18:26 INFO - Reading from file /builds/slave/test-pgo/build/test_packages.json
01:18:26 INFO - Using the following test package requirements:
01:18:26 INFO - {u'common': [u'firefox-43.0a2.en-US.linux-x86_64.common.tests.zip'],
01:18:26 INFO - u'cppunittest': [u'firefox-43.0a2.en-US.linux-x86_64.common.tests.zip',
01:18:26 INFO - u'firefox-43.0a2.en-US.linux-x86_64.cppunittest.tests.zip'],
01:18:26 INFO - u'jittest': [u'firefox-43.0a2.en-US.linux-x86_64.common.tests.zip',
01:18:26 INFO - u'jsshell-linux-x86_64.zip'],
01:18:26 INFO - u'mochitest': [u'firefox-43.0a2.en-US.linux-x86_64.common.tests.zip',
01:18:26 INFO - u'firefox-43.0a2.en-US.linux-x86_64.mochitest.tests.zip'],
01:18:26 INFO - u'mozbase': [u'firefox-43.0a2.en-US.linux-x86_64.common.tests.zip'],
01:18:26 INFO - u'reftest': [u'firefox-43.0a2.en-US.linux-x86_64.common.tests.zip',
01:18:26 INFO - u'firefox-43.0a2.en-US.linux-x86_64.reftest.tests.zip'],
01:18:26 INFO - u'talos': [u'firefox-43.0a2.en-US.linux-x86_64.common.tests.zip',
01:18:26 INFO - u'firefox-43.0a2.en-US.linux-x86_64.talos.tests.zip'],
01:18:26 INFO - u'web-platform': [u'firefox-43.0a2.en-US.linux-x86_64.common.tests.zip',
01:18:26 INFO - u'firefox-43.0a2.en-US.linux-x86_64.web-platform.tests.zip'],
01:18:26 INFO - u'webapprt': [u'firefox-43.0a2.en-US.linux-x86_64.common.tests.zip'],
01:18:26 INFO - u'xpcshell': [u'firefox-43.0a2.en-US.linux-x86_64.common.tests.zip',
01:18:26 INFO - u'firefox-43.0a2.en-US.linux-x86_64.xpcshell.tests.zip']}
01:18:26 INFO - Downloading packages: [u'firefox-43.0a2.en-US.linux-x86_64.common.tests.zip'] for test suite category: common
01:18:26 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
01:18:26 INFO - https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip matches https://queue.taskcluster.net
01:18:26 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip
01:18:26 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip
01:18:26 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip to /builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip
01:18:26 INFO - retry: Calling _download_file with args: (u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip', u'/builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip'), kwargs: {}, attempt #1
01:18:37 INFO - Downloaded 22907380 bytes.
01:18:37 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip'] in /builds/slave/test-pgo/build/tests
01:18:37 INFO - Copy/paste: unzip -q -o /builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip
01:18:37 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip'] with output_timeout 1760
01:18:38 INFO - Return code: 0
01:18:38 INFO - Downloading packages: [u'firefox-43.0a2.en-US.linux-x86_64.common.tests.zip', u'firefox-43.0a2.en-US.linux-x86_64.talos.tests.zip'] for test suite category: talos
01:18: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:18:38 INFO - https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip matches https://queue.taskcluster.net
01:18:38 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip
01:18:38 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip
01:18:38 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip to /builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip
01:18:38 INFO - retry: Calling _download_file with args: (u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip', u'/builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip'), kwargs: {}, attempt #1
01:18:39 INFO - Downloaded 22907380 bytes.
01:18:39 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip'] in /builds/slave/test-pgo/build/tests
01:18:39 INFO - Copy/paste: unzip -q -o /builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip
01:18:39 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip'] with output_timeout 1760
01:18:40 INFO - Return code: 0
01:18:40 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:40 INFO - https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.talos.tests.zip matches https://queue.taskcluster.net
01:18:40 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.talos.tests.zip
01:18:40 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.talos.tests.zip
01:18:40 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.talos.tests.zip to /builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.talos.tests.zip
01:18:40 INFO - retry: Calling _download_file with args: (u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.talos.tests.zip', u'/builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.talos.tests.zip'), kwargs: {}, attempt #1
01:18:41 INFO - Downloaded 10881672 bytes.
01:18:41 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.talos.tests.zip'] in /builds/slave/test-pgo/build/tests
01:18:41 INFO - Copy/paste: unzip -q -o /builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.talos.tests.zip
01:18:41 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.talos.tests.zip'] with output_timeout 1760
01:18:42 INFO - Return code: 0
01:18:42 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:42 INFO - https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2 matches https://queue.taskcluster.net
01:18:42 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2
01:18:42 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2
01:18:42 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2 to /builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2
01:18:42 INFO - retry: Calling _download_file with args: ('http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2', '/builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2'), kwargs: {}, attempt #1
01:18:44 INFO - Downloaded 56990127 bytes.
01:18:44 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2
01:18:44 INFO - mkdir: /builds/slave/test-pgo/properties
01:18:44 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test-pgo/properties/build_url
01:18:44 INFO - Writing to file /builds/slave/test-pgo/properties/build_url
01:18:44 INFO - Contents:
01:18:44 INFO - build_url:https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2
01:18:44 INFO - Running post-action listener: _resource_record_post_action
01:18:44 INFO - Running post-action listener: _set_extra_try_arguments
01:18:44 INFO - #####
01:18:44 INFO - ##### Running populate-webroot step.
01:18:44 INFO - #####
01:18:44 INFO - Running pre-action listener: _resource_record_pre_action
01:18:44 INFO - Running main action method: populate_webroot
01:18:44 INFO - Populating webroot /builds/slave/test-pgo/../talos-data...
01:18:44 INFO - rmtree: /builds/slave/test-pgo/../talos-data/talos
01:18:44 INFO - retry: Calling rmtree with args: ('/builds/slave/test-pgo/../talos-data/talos',), kwargs: {}, attempt #1
01:18:49 INFO - copying tree: /builds/slave/test-pgo/build/tests/talos/talos to /builds/slave/test-pgo/../talos-data/talos
01:18:49 INFO - rmtree: /builds/slave/test-pgo/../talos-data/talos
01:18:49 INFO - Running post-action listener: _resource_record_post_action
01:18:49 INFO - #####
01:18:49 INFO - ##### Running create-virtualenv step.
01:18:49 INFO - #####
01:18:49 INFO - Running pre-action listener: _resource_record_pre_action
01:18:49 INFO - Running main action method: create_virtualenv
01:18:49 INFO - Creating virtualenv /builds/slave/test-pgo/build/venv
01:18:49 INFO - Running command: ['/tools/buildbot/bin/python', '/tools/misc-python/virtualenv.py', '--no-site-packages', '--distribute', '/builds/slave/test-pgo/build/venv'] in /builds/slave/test-pgo/build
01:18:49 INFO - Copy/paste: /tools/buildbot/bin/python /tools/misc-python/virtualenv.py --no-site-packages --distribute /builds/slave/test-pgo/build/venv
01:18:49 INFO - The --no-site-packages flag is deprecated; it is now the default behavior.
01:18:49 INFO - Using real prefix '/usr'
01:18:49 INFO - New python executable in /builds/slave/test-pgo/build/venv/bin/python
01:18:50 INFO - Installing distribute.............................................................................................................................................................................................done.
01:18:52 INFO - Installing pip.................done.
01:18:52 INFO - Return code: 0
01:18:52 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test-pgo/build/venv
01:18:52 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
01:18:52 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
01:18:52 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:18:52 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
01:18:52 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
01:18:52 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:18:52 INFO - retry: Calling run_command with args: [['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test-pgo/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 0x7f6bc51ddb90>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1a267b0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1aeb4a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x187dbf0>, '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 0x1b7b4f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b7b9a0>, 'level': 'critical'}], 'cwd': '/builds/slave/test-pgo/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test-pgo', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1
01:18:52 INFO - Running command: ['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test-pgo/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-pgo/build
01:18:52 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/pip install --download-cache /builds/slave/test-pgo/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:52 INFO - Using env: {'DISPLAY': ':0',
01:18:52 INFO - 'HOME': '/home/cltbld',
01:18:52 INFO - 'LANG': 'en_US.UTF-8',
01:18:52 INFO - 'LANGUAGE': 'en_US:en',
01:18:52 INFO - 'LOGNAME': 'cltbld',
01:18:52 INFO - 'MAIL': '/var/mail/cltbld',
01:18:52 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
01:18:52 INFO - 'MOZ_NO_REMOTE': '1',
01:18:52 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
01:18:52 INFO - 'NO_EM_RESTART': '1',
01:18:52 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
01:18:52 INFO - 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json',
01:18:52 INFO - 'PWD': '/builds/slave/test-pgo',
01:18:52 INFO - 'SHELL': '/bin/bash',
01:18:52 INFO - 'SHLVL': '1',
01:18:52 INFO - 'TERM': 'linux',
01:18:52 INFO - 'TMOUT': '86400',
01:18:52 INFO - 'USER': 'cltbld',
01:18:52 INFO - 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661',
01:18:52 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
01:18:52 INFO - '_': '/tools/buildbot/bin/python'}
01:18:52 INFO - Ignoring indexes: https://pypi.python.org/simple/
01:18:52 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:52 INFO - Cleaning up...
01:18:52 INFO - Return code: 0
01:18:52 INFO - Installing psutil>=0.7.1 into virtualenv /builds/slave/test-pgo/build/venv
01:18:52 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
01:18:52 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
01:18:52 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:18:52 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
01:18:52 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
01:18:52 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:18:52 INFO - retry: Calling run_command with args: [['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test-pgo/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 0x7f6bc51ddb90>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1a267b0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1aeb4a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x187dbf0>, '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 0x1b7b4f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b7b9a0>, 'level': 'critical'}], 'cwd': '/builds/slave/test-pgo/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test-pgo', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1
01:18:52 INFO - Running command: ['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test-pgo/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-pgo/build
01:18:52 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/pip install --download-cache /builds/slave/test-pgo/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:52 INFO - Using env: {'DISPLAY': ':0',
01:18:52 INFO - 'HOME': '/home/cltbld',
01:18:52 INFO - 'LANG': 'en_US.UTF-8',
01:18:52 INFO - 'LANGUAGE': 'en_US:en',
01:18:52 INFO - 'LOGNAME': 'cltbld',
01:18:52 INFO - 'MAIL': '/var/mail/cltbld',
01:18:52 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
01:18:52 INFO - 'MOZ_NO_REMOTE': '1',
01:18:52 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
01:18:52 INFO - 'NO_EM_RESTART': '1',
01:18:52 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
01:18:52 INFO - 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json',
01:18:52 INFO - 'PWD': '/builds/slave/test-pgo',
01:18:52 INFO - 'SHELL': '/bin/bash',
01:18:52 INFO - 'SHLVL': '1',
01:18:52 INFO - 'TERM': 'linux',
01:18:52 INFO - 'TMOUT': '86400',
01:18:52 INFO - 'USER': 'cltbld',
01:18:52 INFO - 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661',
01:18:52 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
01:18:52 INFO - '_': '/tools/buildbot/bin/python'}
01:18:53 INFO - Ignoring indexes: https://pypi.python.org/simple/
01:18:53 INFO - Downloading/unpacking psutil>=0.7.1
01:18:53 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:53 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:53 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:53 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:53 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:53 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:54 INFO - Creating supposed download cache at /builds/slave/test-pgo/build/venv/cache
01:18:54 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:54 INFO - Running setup.py (path:/builds/slave/test-pgo/build/venv/build/psutil/setup.py) egg_info for package psutil
01:18:54 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build'
01:18:54 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects
...
01:18:54 INFO - Installing collected packages: psutil
01:18:54 INFO - Running setup.py install for psutil
01:18:54 INFO - building 'psutil._psutil_linux' extension
01:18:54 INFO - gcc -pthread -fno-strict-aliasing -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -fPIC -DPSUTIL_VERSION=311 -I/usr/include/python2.7 -c psutil/_psutil_linux.c -o build/temp.linux-x86_64-2.7/psutil/_psutil_linux.o
01:18:55 INFO - gcc -pthread -shared -Wl,-O1 -Wl,-Bsymbolic-functions -Wl,-Bsymbolic-functions -Wl,-z,relro build/temp.linux-x86_64-2.7/psutil/_psutil_linux.o -o build/lib.linux-x86_64-2.7/psutil/_psutil_linux.so
01:18:56 INFO - building 'psutil._psutil_posix' extension
01:18:56 INFO - gcc -pthread -fno-strict-aliasing -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -fPIC -I/usr/include/python2.7 -c psutil/_psutil_posix.c -o build/temp.linux-x86_64-2.7/psutil/_psutil_posix.o
01:18:56 INFO - gcc -pthread -shared -Wl,-O1 -Wl,-Bsymbolic-functions -Wl,-Bsymbolic-functions -Wl,-z,relro build/temp.linux-x86_64-2.7/psutil/_psutil_posix.o -o build/lib.linux-x86_64-2.7/psutil/_psutil_posix.so
01:18:56 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build'
01:18:56 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ...
01:18:56 INFO - Successfully installed psutil
01:18:56 INFO - Cleaning up...
01:18:56 INFO - Return code: 0
01:18:56 INFO - Installing mozsystemmonitor==0.0.0 into virtualenv /builds/slave/test-pgo/build/venv
01:18:56 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:56 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
01:18:56 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:18:56 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:56 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
01:18:56 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:18:56 INFO - retry: Calling run_command with args: [['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test-pgo/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 0x7f6bc51ddb90>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1a267b0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1aeb4a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x187dbf0>, '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 0x1b7b4f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b7b9a0>, 'level': 'critical'}], 'cwd': '/builds/slave/test-pgo/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test-pgo', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1
01:18:56 INFO - Running command: ['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test-pgo/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-pgo/build
01:18:56 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/pip install --download-cache /builds/slave/test-pgo/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:56 INFO - Using env: {'DISPLAY': ':0',
01:18:56 INFO - 'HOME': '/home/cltbld',
01:18:56 INFO - 'LANG': 'en_US.UTF-8',
01:18:56 INFO - 'LANGUAGE': 'en_US:en',
01:18:56 INFO - 'LOGNAME': 'cltbld',
01:18:56 INFO - 'MAIL': '/var/mail/cltbld',
01:18:56 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
01:18:56 INFO - 'MOZ_NO_REMOTE': '1',
01:18:56 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
01:18:56 INFO - 'NO_EM_RESTART': '1',
01:18:56 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
01:18:56 INFO - 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json',
01:18:56 INFO - 'PWD': '/builds/slave/test-pgo',
01:18:56 INFO - 'SHELL': '/bin/bash',
01:18:56 INFO - 'SHLVL': '1',
01:18:56 INFO - 'TERM': 'linux',
01:18:56 INFO - 'TMOUT': '86400',
01:18:56 INFO - 'USER': 'cltbld',
01:18:56 INFO - 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661',
01:18:56 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
01:18:56 INFO - '_': '/tools/buildbot/bin/python'}
01:18:56 INFO - Ignoring indexes: https://pypi.python.org/simple/
01:18:56 INFO - Downloading/unpacking mozsystemmonitor==0.0.0
01:18:56 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:56 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:56 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:56 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:56 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:56 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:58 INFO - Downloading mozsystemmonitor-0.0.tar.gz
01:18:58 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fmozsystemmonitor-0.0.tar.gz
01:18:58 INFO - Running setup.py (path:/builds/slave/test-pgo/build/venv/build/mozsystemmonitor/setup.py) egg_info for package mozsystemmonitor
01:18:58 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:58 INFO - Installing collected packages: mozsystemmonitor
01:18:58 INFO - Running setup.py install for mozsystemmonitor
01:18:58 INFO - Successfully installed mozsystemmonitor
01:18:58 INFO - Cleaning up...
01:18:58 INFO - Return code: 0
01:18:58 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test-pgo/build/venv
01:18:58 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:58 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
01:18:58 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:18:58 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:58 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
01:18:58 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:18:58 INFO - retry: Calling run_command with args: [['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test-pgo/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 0x7f6bc51ddb90>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1a267b0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1aeb4a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x187dbf0>, '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 0x1b7b4f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b7b9a0>, 'level': 'critical'}], 'cwd': '/builds/slave/test-pgo/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test-pgo', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1
01:18:58 INFO - Running command: ['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test-pgo/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-pgo/build
01:18:58 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/pip install --download-cache /builds/slave/test-pgo/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:58 INFO - Using env: {'DISPLAY': ':0',
01:18:58 INFO - 'HOME': '/home/cltbld',
01:18:58 INFO - 'LANG': 'en_US.UTF-8',
01:18:58 INFO - 'LANGUAGE': 'en_US:en',
01:18:58 INFO - 'LOGNAME': 'cltbld',
01:18:58 INFO - 'MAIL': '/var/mail/cltbld',
01:18:58 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
01:18:58 INFO - 'MOZ_NO_REMOTE': '1',
01:18:58 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
01:18:58 INFO - 'NO_EM_RESTART': '1',
01:18:58 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
01:18:58 INFO - 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json',
01:18:58 INFO - 'PWD': '/builds/slave/test-pgo',
01:18:58 INFO - 'SHELL': '/bin/bash',
01:18:58 INFO - 'SHLVL': '1',
01:18:58 INFO - 'TERM': 'linux',
01:18:58 INFO - 'TMOUT': '86400',
01:18:58 INFO - 'USER': 'cltbld',
01:18:58 INFO - 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661',
01:18:58 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
01:18:58 INFO - '_': '/tools/buildbot/bin/python'}
01:18:58 INFO - Ignoring indexes: https://pypi.python.org/simple/
01:18:58 INFO - Downloading/unpacking blobuploader==1.2.4
01:18:58 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:58 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:58 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:58 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:58 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:58 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:19:00 INFO - Downloading blobuploader-1.2.4.tar.gz
01:19:00 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fblobuploader-1.2.4.tar.gz
01:19:00 INFO - Running setup.py (path:/builds/slave/test-pgo/build/venv/build/blobuploader/setup.py) egg_info for package blobuploader
01:19:00 INFO - Downloading/unpacking requests==1.2.3. (from blobuploader==1.2.4)
01:19:00 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:19:00 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:19:00 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:19:00 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:19:00 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:19:00 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:19:00 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Frequests-1.2.3.tar.gz
01:19:00 INFO - Running setup.py (path:/builds/slave/test-pgo/build/venv/build/requests/setup.py) egg_info for package requests
01:19:00 INFO - Downloading/unpacking docopt==0.6.1 (from blobuploader==1.2.4)
01:19:00 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:19:00 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:19:00 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:19:00 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:19:00 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:19:00 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:19:00 INFO - Downloading docopt-0.6.1.tar.gz
01:19:00 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fdocopt-0.6.1.tar.gz
01:19:00 INFO - Running setup.py (path:/builds/slave/test-pgo/build/venv/build/docopt/setup.py) egg_info for package docopt
01:19:01 INFO - Installing collected packages: blobuploader, requests, docopt
01:19:01 INFO - Running setup.py install for blobuploader
01:19:01 INFO - changing mode of build/scripts-2.7/blobberc.py from 664 to 775
01:19:01 INFO - changing mode of /builds/slave/test-pgo/build/venv/bin/blobberc.py to 775
01:19:01 INFO - Running setup.py install for requests
01:19:01 INFO - Running setup.py install for docopt
01:19:01 INFO - Successfully installed blobuploader requests docopt
01:19:01 INFO - Cleaning up...
01:19:01 INFO - Return code: 0
01:19:01 INFO - Installing None into virtualenv /builds/slave/test-pgo/build/venv
01:19:01 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:01 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
01:19:01 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:19:01 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:01 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
01:19:01 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:19:01 INFO - retry: Calling run_command with args: [['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--no-deps', '--download-cache', '/builds/slave/test-pgo/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test-pgo/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 0x7f6bc51ddb90>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1a267b0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1aeb4a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x187dbf0>, '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 0x1b7b4f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b7b9a0>, 'level': 'critical'}], 'cwd': '/builds/slave/test-pgo/build/tests/config', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test-pgo', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1
01:19:01 INFO - Running command: ['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--no-deps', '--download-cache', '/builds/slave/test-pgo/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test-pgo/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-pgo/build/tests/config
01:19:01 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/pip install --no-deps --download-cache /builds/slave/test-pgo/build/venv/cache --timeout 120 -r /builds/slave/test-pgo/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:19:01 INFO - Using env: {'DISPLAY': ':0',
01:19:01 INFO - 'HOME': '/home/cltbld',
01:19:01 INFO - 'LANG': 'en_US.UTF-8',
01:19:01 INFO - 'LANGUAGE': 'en_US:en',
01:19:01 INFO - 'LOGNAME': 'cltbld',
01:19:01 INFO - 'MAIL': '/var/mail/cltbld',
01:19:01 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
01:19:01 INFO - 'MOZ_NO_REMOTE': '1',
01:19:01 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
01:19:01 INFO - 'NO_EM_RESTART': '1',
01:19:01 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
01:19:01 INFO - 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json',
01:19:01 INFO - 'PWD': '/builds/slave/test-pgo',
01:19:01 INFO - 'SHELL': '/bin/bash',
01:19:01 INFO - 'SHLVL': '1',
01:19:01 INFO - 'TERM': 'linux',
01:19:01 INFO - 'TMOUT': '86400',
01:19:01 INFO - 'USER': 'cltbld',
01:19:01 INFO - 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661',
01:19:01 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
01:19:01 INFO - '_': '/tools/buildbot/bin/python'}
01:19:01 INFO - Ignoring indexes: https://pypi.python.org/simple/
01:19:01 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/manifestparser
01:19:01 INFO - Running setup.py (path:/tmp/pip-yMCeYo-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/manifestparser
01:19:01 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozcrash
01:19:01 INFO - Running setup.py (path:/tmp/pip-rhzFxh-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozcrash
01:19:01 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozdebug
01:19:02 INFO - Running setup.py (path:/tmp/pip-B9IsMq-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozdebug
01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozdevice
01:19:02 INFO - Running setup.py (path:/tmp/pip-FWnsW4-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozdevice
01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozfile
01:19:02 INFO - Running setup.py (path:/tmp/pip-eObE8G-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozfile
01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozhttpd
01:19:02 INFO - Running setup.py (path:/tmp/pip-t_xBid-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozhttpd
01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozinfo
01:19:02 INFO - Running setup.py (path:/tmp/pip-RknFQf-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozinfo
01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozinstall
01:19:02 INFO - Running setup.py (path:/tmp/pip-om1db6-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozinstall
01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozleak
01:19:02 INFO - Running setup.py (path:/tmp/pip-E2qN6M-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozleak
01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozlog
01:19:02 INFO - Running setup.py (path:/tmp/pip-8XZrWX-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozlog
01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/moznetwork
01:19:02 INFO - Running setup.py (path:/tmp/pip-YsMlaA-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/moznetwork
01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozprocess
01:19:02 INFO - Running setup.py (path:/tmp/pip-sByJIb-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozprocess
01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozprofile
01:19:02 INFO - Running setup.py (path:/tmp/pip-rcIHZJ-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozprofile
01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozrunner
01:19:02 INFO - Running setup.py (path:/tmp/pip-WjHYg0-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozrunner
01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozscreenshot
01:19:02 INFO - Running setup.py (path:/tmp/pip-Aqm76F-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozscreenshot
01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/moztest
01:19:02 INFO - Running setup.py (path:/tmp/pip-x9SwlR-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/moztest
01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozversion
01:19:03 INFO - Running setup.py (path:/tmp/pip-GHLuYA-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozversion
01:19:03 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion
01:19:03 INFO - Running setup.py install for manifestparser
01:19:03 INFO - Installing manifestparser script to /builds/slave/test-pgo/build/venv/bin
01:19:03 INFO - Running setup.py install for mozcrash
01:19:03 INFO - Running setup.py install for mozdebug
01:19:03 INFO - Running setup.py install for mozdevice
01:19:03 INFO - Installing sutini script to /builds/slave/test-pgo/build/venv/bin
01:19:03 INFO - Installing dm script to /builds/slave/test-pgo/build/venv/bin
01:19:03 INFO - Running setup.py install for mozfile
01:19:03 INFO - Running setup.py install for mozhttpd
01:19:03 INFO - Installing mozhttpd script to /builds/slave/test-pgo/build/venv/bin
01:19:03 INFO - Running setup.py install for mozinfo
01:19:03 INFO - Installing mozinfo script to /builds/slave/test-pgo/build/venv/bin
01:19:03 INFO - Running setup.py install for mozInstall
01:19:03 INFO - Installing moz_remove_from_system script to /builds/slave/test-pgo/build/venv/bin
01:19:03 INFO - Installing mozuninstall script to /builds/slave/test-pgo/build/venv/bin
01:19:03 INFO - Installing mozinstall script to /builds/slave/test-pgo/build/venv/bin
01:19:03 INFO - Installing moz_add_to_system script to /builds/slave/test-pgo/build/venv/bin
01:19:03 INFO - Running setup.py install for mozleak
01:19:03 INFO - Running setup.py install for mozlog
01:19:04 INFO - Installing structlog script to /builds/slave/test-pgo/build/venv/bin
01:19:04 INFO - Running setup.py install for moznetwork
01:19:04 INFO - Installing moznetwork script to /builds/slave/test-pgo/build/venv/bin
01:19:04 INFO - Running setup.py install for mozprocess
01:19:04 INFO - Running setup.py install for mozprofile
01:19:04 INFO - Installing mozprofile script to /builds/slave/test-pgo/build/venv/bin
01:19:04 INFO - Installing diff-profiles script to /builds/slave/test-pgo/build/venv/bin
01:19:04 INFO - Installing view-profile script to /builds/slave/test-pgo/build/venv/bin
01:19:04 INFO - Running setup.py install for mozrunner
01:19:04 INFO - Installing mozrunner script to /builds/slave/test-pgo/build/venv/bin
01:19:04 INFO - Running setup.py install for mozscreenshot
01:19:04 INFO - Running setup.py install for moztest
01:19:04 INFO - Running setup.py install for mozversion
01:19:04 INFO - Installing mozversion script to /builds/slave/test-pgo/build/venv/bin
01:19:04 INFO - Successfully installed manifestparser mozcrash mozdebug mozdevice mozfile mozhttpd mozinfo mozInstall mozleak mozlog moznetwork mozprocess mozprofile mozrunner mozscreenshot moztest mozversion
01:19:04 INFO - Cleaning up...
01:19:04 INFO - Return code: 0
01:19:04 INFO - Installing None into virtualenv /builds/slave/test-pgo/build/venv
01:19:04 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
01:19:04 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
01:19:04 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:19:04 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
01:19:04 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
01:19:04 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:19:04 INFO - retry: Calling run_command with args: [['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test-pgo/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test-pgo/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 0x7f6bc51ddb90>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1a267b0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1aeb4a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x187dbf0>, '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 0x1b7b4f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b7b9a0>, 'level': 'critical'}], 'cwd': '/builds/slave/test-pgo/build/tests/config', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test-pgo', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1
01:19:04 INFO - Running command: ['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test-pgo/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test-pgo/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-pgo/build/tests/config
01:19:04 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/pip install --download-cache /builds/slave/test-pgo/build/venv/cache --timeout 120 -r /builds/slave/test-pgo/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:19:04 INFO - Using env: {'DISPLAY': ':0',
01:19:04 INFO - 'HOME': '/home/cltbld',
01:19:04 INFO - 'LANG': 'en_US.UTF-8',
01:19:04 INFO - 'LANGUAGE': 'en_US:en',
01:19:04 INFO - 'LOGNAME': 'cltbld',
01:19:04 INFO - 'MAIL': '/var/mail/cltbld',
01:19:04 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
01:19:04 INFO - 'MOZ_NO_REMOTE': '1',
01:19:04 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
01:19:04 INFO - 'NO_EM_RESTART': '1',
01:19:04 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
01:19:04 INFO - 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json',
01:19:04 INFO - 'PWD': '/builds/slave/test-pgo',
01:19:04 INFO - 'SHELL': '/bin/bash',
01:19:04 INFO - 'SHLVL': '1',
01:19:04 INFO - 'TERM': 'linux',
01:19:04 INFO - 'TMOUT': '86400',
01:19:04 INFO - 'USER': 'cltbld',
01:19:04 INFO - 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661',
01:19:04 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
01:19:04 INFO - '_': '/tools/buildbot/bin/python'}
01:19:05 INFO - Ignoring indexes: https://pypi.python.org/simple/
01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/manifestparser
01:19:05 INFO - Running setup.py (path:/tmp/pip-KPM7uk-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/manifestparser
01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): manifestparser==1.1 from file:///builds/slave/test-pgo/build/tests/mozbase/manifestparser in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 1))
01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozcrash
01:19:05 INFO - Running setup.py (path:/tmp/pip-DtjJz4-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozcrash
01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash==0.16 from file:///builds/slave/test-pgo/build/tests/mozbase/mozcrash in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 2))
01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozdebug
01:19:05 INFO - Running setup.py (path:/tmp/pip-2KMWDP-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozdebug
01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdebug==0.1 from file:///builds/slave/test-pgo/build/tests/mozbase/mozdebug in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 3))
01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozdevice
01:19:05 INFO - Running setup.py (path:/tmp/pip-E6SoEi-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozdevice
01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdevice==0.46 from file:///builds/slave/test-pgo/build/tests/mozbase/mozdevice in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 4))
01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozfile
01:19:05 INFO - Running setup.py (path:/tmp/pip-_8K4qe-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozfile
01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile==1.2 from file:///builds/slave/test-pgo/build/tests/mozbase/mozfile in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 5))
01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozhttpd
01:19:05 INFO - Running setup.py (path:/tmp/pip-FsS5qr-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozhttpd
01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd==0.7 from file:///builds/slave/test-pgo/build/tests/mozbase/mozhttpd in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 6))
01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozinfo
01:19:05 INFO - Running setup.py (path:/tmp/pip-q1ziry-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozinfo
01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo==0.8 from file:///builds/slave/test-pgo/build/tests/mozbase/mozinfo in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 7))
01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozinstall
01:19:05 INFO - Running setup.py (path:/tmp/pip-Hk5v46-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozinstall
01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozInstall==1.12 from file:///builds/slave/test-pgo/build/tests/mozbase/mozinstall in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 8))
01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozleak
01:19:05 INFO - Running setup.py (path:/tmp/pip-04iOTN-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozleak
01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozleak==0.1 from file:///builds/slave/test-pgo/build/tests/mozbase/mozleak in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 9))
01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozlog
01:19:05 INFO - Running setup.py (path:/tmp/pip-KlKbrW-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozlog
01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog==3.0 from file:///builds/slave/test-pgo/build/tests/mozbase/mozlog in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 10))
01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/moznetwork
01:19:05 INFO - Running setup.py (path:/tmp/pip-lB34sR-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/moznetwork
01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork==0.27 from file:///builds/slave/test-pgo/build/tests/mozbase/moznetwork in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 11))
01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozprocess
01:19:05 INFO - Running setup.py (path:/tmp/pip-xxeZov-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozprocess
01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess==0.22 from file:///builds/slave/test-pgo/build/tests/mozbase/mozprocess in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 12))
01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozprofile
01:19:05 INFO - Running setup.py (path:/tmp/pip-kcD6y1-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozprofile
01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile==0.27 from file:///builds/slave/test-pgo/build/tests/mozbase/mozprofile in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 13))
01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozrunner
01:19:05 INFO - Running setup.py (path:/tmp/pip-YCt3fr-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozrunner
01:19:06 INFO - Requirement already satisfied (use --upgrade to upgrade): mozrunner==6.10 from file:///builds/slave/test-pgo/build/tests/mozbase/mozrunner in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 14))
01:19:06 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozscreenshot
01:19:06 INFO - Running setup.py (path:/tmp/pip-S5xTYJ-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozscreenshot
01:19:06 INFO - Requirement already satisfied (use --upgrade to upgrade): mozscreenshot==0.1 from file:///builds/slave/test-pgo/build/tests/mozbase/mozscreenshot in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 15))
01:19:06 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/moztest
01:19:06 INFO - Running setup.py (path:/tmp/pip-EuToUc-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/moztest
01:19:06 INFO - Requirement already satisfied (use --upgrade to upgrade): moztest==0.7 from file:///builds/slave/test-pgo/build/tests/mozbase/moztest in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 16))
01:19:06 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozversion
01:19:06 INFO - Running setup.py (path:/tmp/pip-pMR9Ds-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozversion
01:19:06 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion==1.4 from file:///builds/slave/test-pgo/build/tests/mozbase/mozversion in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 17))
01:19:06 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.0 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from mozcrash==0.16->-r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 2))
01:19:06 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.0 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from mozcrash==0.16->-r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 2))
01:19:06 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from mozdebug==0.1->-r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 3))
01:19:06 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork>=0.24 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from mozdevice==0.46->-r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 4))
01:19:06 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.19 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from mozdevice==0.46->-r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 4))
01:19:06 INFO - Downloading/unpacking blessings>=1.3 (from mozlog==3.0->-r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 10))
01:19:06 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:19:06 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:19:06 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:19:06 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:19:06 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:19:06 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:19:07 INFO - Downloading blessings-1.5.1.tar.gz
01:19:07 INFO - Storing download in cache at /builds/slave/test-pgo/build/venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fblessings-1.5.1.tar.gz
01:19:07 INFO - Running setup.py (path:/builds/slave/test-pgo/build/venv/build/blessings/setup.py) egg_info for package blessings
01:19:08 INFO - Installing collected packages: blessings
01:19:08 INFO - Running setup.py install for blessings
01:19:08 INFO - Successfully installed blessings
01:19:08 INFO - Cleaning up...
01:19:08 INFO - Return code: 0
01:19:08 INFO - Done creating virtualenv /builds/slave/test-pgo/build/venv.
01:19:08 INFO - Getting output from command: ['/builds/slave/test-pgo/build/venv/bin/pip', 'freeze']
01:19:08 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/pip freeze
01:19:08 INFO - Reading from file tmpfile_stdout
01:19:08 INFO - Current package versions:
01:19:08 INFO - argparse == 1.2.1
01:19:08 INFO - blessings == 1.5.1
01:19:08 INFO - blobuploader == 1.2.4
01:19:08 INFO - docopt == 0.6.1
01:19:08 INFO - manifestparser == 1.1
01:19:08 INFO - mozInstall == 1.12
01:19:08 INFO - mozcrash == 0.16
01:19:08 INFO - mozdebug == 0.1
01:19:08 INFO - mozdevice == 0.46
01:19:08 INFO - mozfile == 1.2
01:19:08 INFO - mozhttpd == 0.7
01:19:08 INFO - mozinfo == 0.8
01:19:08 INFO - mozleak == 0.1
01:19:08 INFO - mozlog == 3.0
01:19:08 INFO - moznetwork == 0.27
01:19:08 INFO - mozprocess == 0.22
01:19:08 INFO - mozprofile == 0.27
01:19:08 INFO - mozrunner == 6.10
01:19:08 INFO - mozscreenshot == 0.1
01:19:08 INFO - mozsystemmonitor == 0.0
01:19:08 INFO - moztest == 0.7
01:19:08 INFO - mozversion == 1.4
01:19:08 INFO - psutil == 3.1.1
01:19:08 INFO - requests == 1.2.3
01:19:08 INFO - wsgiref == 0.1.2
01:19:08 INFO - Installing None into virtualenv /builds/slave/test-pgo/build/venv
01:19:08 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:08 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
01:19:08 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:19:08 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:08 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
01:19:08 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
01:19:08 INFO - retry: Calling run_command with args: [['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test-pgo/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test-pgo/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 0x7f6bc51ddb90>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1a267b0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1aeb4a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x187dbf0>, '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 0x1b7b4f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b7b9a0>, 'level': 'critical'}], 'cwd': '/builds/slave/test-pgo/build/tests/talos', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test-pgo', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1
01:19:08 INFO - Running command: ['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test-pgo/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test-pgo/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-pgo/build/tests/talos
01:19:08 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/pip install --download-cache /builds/slave/test-pgo/build/venv/cache --timeout 120 -r /builds/slave/test-pgo/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:19:08 INFO - Using env: {'DISPLAY': ':0',
01:19:08 INFO - 'HOME': '/home/cltbld',
01:19:08 INFO - 'LANG': 'en_US.UTF-8',
01:19:08 INFO - 'LANGUAGE': 'en_US:en',
01:19:08 INFO - 'LOGNAME': 'cltbld',
01:19:08 INFO - 'MAIL': '/var/mail/cltbld',
01:19:08 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
01:19:08 INFO - 'MOZ_NO_REMOTE': '1',
01:19:08 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
01:19:08 INFO - 'NO_EM_RESTART': '1',
01:19:08 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
01:19:08 INFO - 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json',
01:19:08 INFO - 'PWD': '/builds/slave/test-pgo',
01:19:08 INFO - 'SHELL': '/bin/bash',
01:19:08 INFO - 'SHLVL': '1',
01:19:08 INFO - 'TERM': 'linux',
01:19:08 INFO - 'TMOUT': '86400',
01:19:08 INFO - 'USER': 'cltbld',
01:19:08 INFO - 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661',
01:19:08 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
01:19:08 INFO - '_': '/tools/buildbot/bin/python'}
01:19:08 INFO - Ignoring indexes: https://pypi.python.org/simple/
01:19:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash>=0.15 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/talos/requirements.txt (line 1))
01:19:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.2 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/talos/requirements.txt (line 2))
01:19:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd>=0.7 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/talos/requirements.txt (line 3))
01:19:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo>=0.8 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/talos/requirements.txt (line 4))
01:19:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.22 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/talos/requirements.txt (line 5))
01:19:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion>=1.3 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/talos/requirements.txt (line 6))
01:19:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile>=0.25 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/talos/requirements.txt (line 7))
01:19:08 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/talos/requirements.txt (line 8))
01:19:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.0 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from mozcrash>=0.15->-r /builds/slave/test-pgo/build/tests/talos/requirements.txt (line 1))
01:19:08 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork>=0.24 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from mozhttpd>=0.7->-r /builds/slave/test-pgo/build/tests/talos/requirements.txt (line 3))
01:19:08 INFO - Requirement already satisfied (use --upgrade to upgrade): blessings>=1.3 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from mozlog>=3.0->mozcrash>=0.15->-r /builds/slave/test-pgo/build/tests/talos/requirements.txt (line 1))
01:19:08 INFO - Cleaning up...
01:19:08 INFO - Return code: 0
01:19:08 INFO - Running post-action listener: _resource_record_post_action
01:19:08 INFO - Running post-action listener: _start_resource_monitoring
01:19:08 INFO - Starting resource monitoring.
01:19:08 INFO - #####
01:19:08 INFO - ##### Running install step.
01:19:08 INFO - #####
01:19:08 INFO - Running pre-action listener: _resource_record_pre_action
01:19:08 INFO - Running main action method: install
01:19:08 INFO - Getting output from command: ['/builds/slave/test-pgo/build/venv/bin/pip', 'freeze']
01:19:08 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/pip freeze
01:19:08 INFO - Reading from file tmpfile_stdout
01:19:08 INFO - Detecting whether we're running mozinstall >=1.0...
01:19:08 INFO - Getting output from command: ['/builds/slave/test-pgo/build/venv/bin/mozinstall', '-h']
01:19:08 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/mozinstall -h
01:19:08 INFO - Reading from file tmpfile_stdout
01:19:08 INFO - Output received:
01:19:08 INFO - Usage: mozinstall [options] installer
01:19:08 INFO - Options:
01:19:08 INFO - -h, --help show this help message and exit
01:19:08 INFO - -d DEST, --destination=DEST
01:19:08 INFO - Directory to install application into. [default:
01:19:08 INFO - "/builds/slave/test-pgo"]
01:19:08 INFO - --app=APP Application being installed. [default: firefox]
01:19:08 INFO - mkdir: /builds/slave/test-pgo/build/application
01:19:08 INFO - Getting output from command: ['/builds/slave/test-pgo/build/venv/bin/mozinstall', '/builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2', '--destination', '/builds/slave/test-pgo/build/application']
01:19:08 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/mozinstall /builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2 --destination /builds/slave/test-pgo/build/application
01:19:23 INFO - Reading from file tmpfile_stdout
01:19:23 INFO - Output received:
01:19:23 INFO - /builds/slave/test-pgo/build/application/firefox/firefox
01:19:23 INFO - Running post-action listener: _resource_record_post_action
01:19:23 INFO - #####
01:19:23 INFO - ##### Running run-tests step.
01:19:23 INFO - #####
01:19:23 INFO - Running pre-action listener: _resource_record_pre_action
01:19:23 INFO - Running main action method: run_tests
01:19:23 INFO - Running command: ['/builds/slave/test-pgo/build/venv/bin/python', '--version']
01:19:23 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/python --version
01:19:23 INFO - Python 2.7.3
01:19:23 INFO - Return code: 0
01:19:23 INFO - grabbing minidump binary from tooltool
01:19:23 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
01:19:23 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-pgo/build/tests/config/tooltool-manifests/linux64/releng.manifest', '-o', '-c', '/builds/tooltool_cache'],), kwargs: {'error_list': [{'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x187dbf0>, '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 0x1b7b4f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b7b9a0>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test-pgo/build', 'privileged': False}, attempt #1
01:19:23 INFO - Running command: ['/tools/tooltool.py', '--url', 'https://api.pub.build.mozilla.org/tooltool/', '--authentication-file', '/builds/relengapi.tok', 'fetch', '-m', '/builds/slave/test-pgo/build/tests/config/tooltool-manifests/linux64/releng.manifest', '-o', '-c', '/builds/tooltool_cache'] in /builds/slave/test-pgo/build
01:19:23 INFO - Copy/paste: /tools/tooltool.py --url https://api.pub.build.mozilla.org/tooltool/ --authentication-file /builds/relengapi.tok fetch -m /builds/slave/test-pgo/build/tests/config/tooltool-manifests/linux64/releng.manifest -o -c /builds/tooltool_cache
01:19:23 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache
01:19:23 INFO - Return code: 0
01:19:23 INFO - Chmoding /builds/slave/test-pgo/build/linux64-minidump_stackwalk to 0755
01:19:23 INFO - mkdir: /builds/slave/test-pgo/build/blobber_upload_dir
01:19:23 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test-pgo/build/blobber_upload_dir
01:19:23 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test-pgo/build/linux64-minidump_stackwalk
01:19:23 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test-pgo/build/blobber_upload_dir
01:19:23 INFO - Running command: ['/builds/slave/test-pgo/build/venv/bin/python', '/builds/slave/test-pgo/build/tests/talos/talos/run_tests.py', '--debug', '--branchName', 'Mozilla-Aurora', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.crashreporter-symbols.zip', '--activeTests', 'a11yr:ts_paint:tpaint:sessionrestore:sessionrestore_no_auto_restore', '--executablePath', '/builds/slave/test-pgo/build/application/firefox/firefox', '--title', 'talos-linux64-ix-041', '--webServer', 'localhost'] in /builds/slave/test-pgo/build
01:19:23 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/python /builds/slave/test-pgo/build/tests/talos/talos/run_tests.py --debug --branchName Mozilla-Aurora --symbolsPath https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.crashreporter-symbols.zip --activeTests a11yr:ts_paint:tpaint:sessionrestore:sessionrestore_no_auto_restore --executablePath /builds/slave/test-pgo/build/application/firefox/firefox --title talos-linux64-ix-041 --webServer localhost
01:19:23 INFO - Using env: {'DISPLAY': ':0',
01:19:23 INFO - 'HOME': '/home/cltbld',
01:19:23 INFO - 'LANG': 'en_US.UTF-8',
01:19:23 INFO - 'LANGUAGE': 'en_US:en',
01:19:23 INFO - 'LOGNAME': 'cltbld',
01:19:23 INFO - 'MAIL': '/var/mail/cltbld',
01:19:23 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test-pgo/build/blobber_upload_dir',
01:19:23 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test-pgo/build/linux64-minidump_stackwalk',
01:19:23 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
01:19:23 INFO - 'MOZ_NO_REMOTE': '1',
01:19:23 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test-pgo/build/blobber_upload_dir',
01:19:23 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
01:19:23 INFO - 'NO_EM_RESTART': '1',
01:19:23 INFO - 'PATH': '/builds/slave/test-pgo/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
01:19:23 INFO - 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json',
01:19:23 INFO - 'PWD': '/builds/slave/test-pgo',
01:19:23 INFO - 'PYTHONPATH': '/builds/slave/test-pgo/build/tests/talos',
01:19:23 INFO - 'SHELL': '/bin/bash',
01:19:23 INFO - 'SHLVL': '1',
01:19:23 INFO - 'TERM': 'linux',
01:19:23 INFO - 'TMOUT': '86400',
01:19:23 INFO - 'USER': 'cltbld',
01:19:23 INFO - 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661',
01:19:23 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
01:19:23 INFO - '_': '/tools/buildbot/bin/python'}
01:19:23 INFO - Calling ['/builds/slave/test-pgo/build/venv/bin/python', '/builds/slave/test-pgo/build/tests/talos/talos/run_tests.py', '--debug', '--branchName', 'Mozilla-Aurora', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.crashreporter-symbols.zip', '--activeTests', 'a11yr:ts_paint:tpaint:sessionrestore:sessionrestore_no_auto_restore', '--executablePath', '/builds/slave/test-pgo/build/application/firefox/firefox', '--title', 'talos-linux64-ix-041', '--webServer', 'localhost'] with output_timeout 3600
01:19:23 INFO - mozversion INFO | application_buildid: 20151029014646
01:19:23 INFO - mozversion INFO | application_changeset: 41fdefd640f368bccdeafe6446d42c0a5ad22797
01:19:23 INFO - mozversion INFO | application_display_name: FirefoxDeveloperEdition
01:19:23 INFO - mozversion INFO | application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384}
01:19:23 INFO - mozversion INFO | application_name: Firefox
01:19:23 INFO - mozversion INFO | application_remotingname: firefox-dev
01:19:23 INFO - mozversion INFO | application_repository: https://hg.mozilla.org/releases/mozilla-aurora
01:19:23 INFO - mozversion INFO | application_vendor: Mozilla
01:19:23 INFO - mozversion INFO | application_version: 43.0a2
01:19:23 INFO - mozversion INFO | platform_buildid: 20151029014646
01:19:23 INFO - mozversion INFO | platform_changeset: 41fdefd640f368bccdeafe6446d42c0a5ad22797
01:19:23 INFO - mozversion INFO | platform_repository: https://hg.mozilla.org/releases/mozilla-aurora
01:19:23 INFO - mozversion INFO | platform_version: 43.0a2
01:19:23 INFO - 2015-10-30 01:19:23,886 DEBUG : using testdate: 1446193163
01:19:23 INFO - 2015-10-30 01:19:23,886 DEBUG : actual date: 1446193163
01:19:23 INFO - 2015-10-30 01:19:23,894 INFO : Starting test suite talos-linux64-ix-041
01:19:23 INFO - 2015-10-30 01:19:23,894 INFO : Starting test a11yr
01:19:23 INFO - 2015-10-30 01:19:23,894 DEBUG : operating with platform_type : linux_
01:19:23 INFO - 2015-10-30 01:19:23,895 INFO : Initialising browser for a11yr test...
01:19:23 INFO - 2015-10-30 01:19:23,977 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpfuDupe/profile http://localhost/getInfo.html
01:19:29 INFO - 2015-10-30 01:19:29,586 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
01:19:29 INFO - 2015-10-30 01:19:29,586 DEBUG : BROWSER_OUTPUT: colorDepth:24
01:19:29 INFO - 2015-10-30 01:19:29,586 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697
01:19:29 INFO - 2015-10-30 01:19:29,586 DEBUG : BROWSER_OUTPUT: __metrics
01:19:29 INFO - 2015-10-30 01:19:29,824 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:31 INFO - 2015-10-30 01:19:31,346 INFO : Browser initialized.
01:19:31 INFO - 2015-10-30 01:19:31,347 INFO : Running cycle 1/1 for a11yr test...
01:19:31 INFO - 2015-10-30 01:19:31,347 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpfuDupe/profile -tp file:/builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/a11y.manifest -tpchrome -tpmozafterpaint -tpnoisy -tpcycles 1 -tppagecycles 25
01:19:43 INFO - 2015-10-30 01:19:43,027 DEBUG : BROWSER_OUTPUT: RSS: Main: 131743744
01:19:43 INFO - 2015-10-30 01:19:43,027 DEBUG : BROWSER_OUTPUT:
01:19:43 INFO - 2015-10-30 01:19:43,928 DEBUG : BROWSER_OUTPUT:
01:19:43 INFO - 2015-10-30 01:19:43,928 DEBUG : BROWSER_OUTPUT: (firefox:3404): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed
01:19:43 INFO - 2015-10-30 01:19:43,936 DEBUG : BROWSER_OUTPUT: Cycle 1(1): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:19:44 INFO - 2015-10-30 01:19:44,526 DEBUG : BROWSER_OUTPUT: RSS: Main: 168964096
01:19:44 INFO - 2015-10-30 01:19:44,526 DEBUG : BROWSER_OUTPUT:
01:19:45 INFO - 2015-10-30 01:19:45,513 DEBUG : BROWSER_OUTPUT: Cycle 1(2): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:19:46 INFO - 2015-10-30 01:19:46,154 DEBUG : BROWSER_OUTPUT: RSS: Main: 173899776
01:19:46 INFO - 2015-10-30 01:19:46,154 DEBUG : BROWSER_OUTPUT:
01:19:47 INFO - 2015-10-30 01:19:47,061 DEBUG : BROWSER_OUTPUT: Cycle 1(3): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:19:47 INFO - 2015-10-30 01:19:47,702 DEBUG : BROWSER_OUTPUT: RSS: Main: 173867008
01:19:47 INFO - 2015-10-30 01:19:47,702 DEBUG : BROWSER_OUTPUT:
01:19:48 INFO - 2015-10-30 01:19:48,684 DEBUG : BROWSER_OUTPUT: Cycle 1(4): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:19:49 INFO - 2015-10-30 01:19:49,327 DEBUG : BROWSER_OUTPUT: RSS: Main: 175525888
01:19:49 INFO - 2015-10-30 01:19:49,327 DEBUG : BROWSER_OUTPUT:
01:19:50 INFO - 2015-10-30 01:19:50,313 DEBUG : BROWSER_OUTPUT: Cycle 1(5): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:19:50 INFO - 2015-10-30 01:19:50,956 DEBUG : BROWSER_OUTPUT: RSS: Main: 176009216
01:19:50 INFO - 2015-10-30 01:19:50,957 DEBUG : BROWSER_OUTPUT:
01:19:51 INFO - 2015-10-30 01:19:51,951 DEBUG : BROWSER_OUTPUT: Cycle 1(6): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:19:52 INFO - 2015-10-30 01:19:52,598 DEBUG : BROWSER_OUTPUT: RSS: Main: 176951296
01:19:52 INFO - 2015-10-30 01:19:52,598 DEBUG : BROWSER_OUTPUT:
01:19:53 INFO - 2015-10-30 01:19:53,601 DEBUG : BROWSER_OUTPUT: Cycle 1(7): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:19:54 INFO - 2015-10-30 01:19:54,244 DEBUG : BROWSER_OUTPUT: RSS: Main: 176791552
01:19:54 INFO - 2015-10-30 01:19:54,244 DEBUG : BROWSER_OUTPUT:
01:19:55 INFO - 2015-10-30 01:19:55,247 DEBUG : BROWSER_OUTPUT: Cycle 1(8): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:19:55 INFO - 2015-10-30 01:19:55,889 DEBUG : BROWSER_OUTPUT: RSS: Main: 177963008
01:19:55 INFO - 2015-10-30 01:19:55,890 DEBUG : BROWSER_OUTPUT:
01:19:56 INFO - 2015-10-30 01:19:56,791 DEBUG : BROWSER_OUTPUT: Cycle 1(9): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:19:57 INFO - 2015-10-30 01:19:57,434 DEBUG : BROWSER_OUTPUT: RSS: Main: 176898048
01:19:57 INFO - 2015-10-30 01:19:57,434 DEBUG : BROWSER_OUTPUT:
01:19:58 INFO - 2015-10-30 01:19:58,409 DEBUG : BROWSER_OUTPUT: Cycle 1(10): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:19:59 INFO - 2015-10-30 01:19:59,051 DEBUG : BROWSER_OUTPUT: RSS: Main: 177389568
01:19:59 INFO - 2015-10-30 01:19:59,051 DEBUG : BROWSER_OUTPUT:
01:20:00 INFO - 2015-10-30 01:20:00,033 DEBUG : BROWSER_OUTPUT: Cycle 1(11): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:00 INFO - 2015-10-30 01:20:00,676 DEBUG : BROWSER_OUTPUT: RSS: Main: 177696768
01:20:00 INFO - 2015-10-30 01:20:00,676 DEBUG : BROWSER_OUTPUT:
01:20:01 INFO - 2015-10-30 01:20:01,683 DEBUG : BROWSER_OUTPUT: Cycle 1(12): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:02 INFO - 2015-10-30 01:20:02,330 DEBUG : BROWSER_OUTPUT: RSS: Main: 177278976
01:20:02 INFO - 2015-10-30 01:20:02,330 DEBUG : BROWSER_OUTPUT:
01:20:03 INFO - 2015-10-30 01:20:03,365 DEBUG : BROWSER_OUTPUT: Cycle 1(13): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:04 INFO - 2015-10-30 01:20:04,015 DEBUG : BROWSER_OUTPUT: RSS: Main: 177569792
01:20:04 INFO - 2015-10-30 01:20:04,015 DEBUG : BROWSER_OUTPUT:
01:20:04 INFO - 2015-10-30 01:20:04,998 DEBUG : BROWSER_OUTPUT: Cycle 1(14): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:05 INFO - 2015-10-30 01:20:05,645 DEBUG : BROWSER_OUTPUT: RSS: Main: 176697344
01:20:05 INFO - 2015-10-30 01:20:05,645 DEBUG : BROWSER_OUTPUT:
01:20:06 INFO - 2015-10-30 01:20:06,652 DEBUG : BROWSER_OUTPUT: Cycle 1(15): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:07 INFO - 2015-10-30 01:20:07,298 DEBUG : BROWSER_OUTPUT: RSS: Main: 177803264
01:20:07 INFO - 2015-10-30 01:20:07,299 DEBUG : BROWSER_OUTPUT:
01:20:08 INFO - 2015-10-30 01:20:08,232 DEBUG : BROWSER_OUTPUT: Cycle 1(16): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:08 INFO - 2015-10-30 01:20:08,309 DEBUG : BROWSER_OUTPUT:
01:20:08 INFO - 2015-10-30 01:20:08,309 DEBUG : BROWSER_OUTPUT: (firefox:3404): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed
01:20:08 INFO - 2015-10-30 01:20:08,889 DEBUG : BROWSER_OUTPUT: RSS: Main: 176570368
01:20:08 INFO - 2015-10-30 01:20:08,889 DEBUG : BROWSER_OUTPUT:
01:20:09 INFO - 2015-10-30 01:20:09,897 DEBUG : BROWSER_OUTPUT: Cycle 1(17): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:10 INFO - 2015-10-30 01:20:10,539 DEBUG : BROWSER_OUTPUT: RSS: Main: 177291264
01:20:10 INFO - 2015-10-30 01:20:10,540 DEBUG : BROWSER_OUTPUT:
01:20:11 INFO - 2015-10-30 01:20:11,587 DEBUG : BROWSER_OUTPUT: Cycle 1(18): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:12 INFO - 2015-10-30 01:20:12,229 DEBUG : BROWSER_OUTPUT: RSS: Main: 177049600
01:20:12 INFO - 2015-10-30 01:20:12,229 DEBUG : BROWSER_OUTPUT:
01:20:13 INFO - 2015-10-30 01:20:13,219 DEBUG : BROWSER_OUTPUT: Cycle 1(19): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:13 INFO - 2015-10-30 01:20:13,861 DEBUG : BROWSER_OUTPUT: RSS: Main: 177078272
01:20:13 INFO - 2015-10-30 01:20:13,861 DEBUG : BROWSER_OUTPUT:
01:20:14 INFO - 2015-10-30 01:20:14,935 DEBUG : BROWSER_OUTPUT: Cycle 1(20): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:15 INFO - 2015-10-30 01:20:15,582 DEBUG : BROWSER_OUTPUT: RSS: Main: 176742400
01:20:15 INFO - 2015-10-30 01:20:15,582 DEBUG : BROWSER_OUTPUT:
01:20:16 INFO - 2015-10-30 01:20:16,597 DEBUG : BROWSER_OUTPUT: Cycle 1(21): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:17 INFO - 2015-10-30 01:20:17,239 DEBUG : BROWSER_OUTPUT: RSS: Main: 176521216
01:20:17 INFO - 2015-10-30 01:20:17,239 DEBUG : BROWSER_OUTPUT:
01:20:18 INFO - 2015-10-30 01:20:18,202 DEBUG : BROWSER_OUTPUT: Cycle 1(22): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:18 INFO - 2015-10-30 01:20:18,845 DEBUG : BROWSER_OUTPUT: RSS: Main: 177053696
01:20:18 INFO - 2015-10-30 01:20:18,845 DEBUG : BROWSER_OUTPUT:
01:20:19 INFO - 2015-10-30 01:20:19,827 DEBUG : BROWSER_OUTPUT: Cycle 1(23): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:20 INFO - 2015-10-30 01:20:20,474 DEBUG : BROWSER_OUTPUT: RSS: Main: 176033792
01:20:20 INFO - 2015-10-30 01:20:20,475 DEBUG : BROWSER_OUTPUT:
01:20:21 INFO - 2015-10-30 01:20:21,542 DEBUG : BROWSER_OUTPUT: Cycle 1(24): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:22 INFO - 2015-10-30 01:20:22,189 DEBUG : BROWSER_OUTPUT: RSS: Main: 177061888
01:20:22 INFO - 2015-10-30 01:20:22,189 DEBUG : BROWSER_OUTPUT:
01:20:23 INFO - 2015-10-30 01:20:23,196 DEBUG : BROWSER_OUTPUT: Cycle 1(25): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html)
01:20:23 INFO - 2015-10-30 01:20:23,839 DEBUG : BROWSER_OUTPUT: RSS: Main: 177307648
01:20:23 INFO - 2015-10-30 01:20:23,839 DEBUG : BROWSER_OUTPUT:
01:20:24 INFO - 2015-10-30 01:20:24,419 DEBUG : BROWSER_OUTPUT:
01:20:24 INFO - 2015-10-30 01:20:24,419 DEBUG : BROWSER_OUTPUT: (firefox:3404): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed
01:20:24 INFO - 2015-10-30 01:20:24,440 DEBUG : BROWSER_OUTPUT: Cycle 1(1): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:25 INFO - 2015-10-30 01:20:25,003 DEBUG : BROWSER_OUTPUT: RSS: Main: 173649920
01:20:25 INFO - 2015-10-30 01:20:25,003 DEBUG : BROWSER_OUTPUT:
01:20:25 INFO - 2015-10-30 01:20:25,584 DEBUG : BROWSER_OUTPUT: Cycle 1(2): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:26 INFO - 2015-10-30 01:20:26,147 DEBUG : BROWSER_OUTPUT: RSS: Main: 176496640
01:20:26 INFO - 2015-10-30 01:20:26,147 DEBUG : BROWSER_OUTPUT:
01:20:26 INFO - 2015-10-30 01:20:26,727 DEBUG : BROWSER_OUTPUT: Cycle 1(3): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:27 INFO - 2015-10-30 01:20:27,311 DEBUG : BROWSER_OUTPUT: RSS: Main: 177479680
01:20:27 INFO - 2015-10-30 01:20:27,311 DEBUG : BROWSER_OUTPUT:
01:20:27 INFO - 2015-10-30 01:20:27,891 DEBUG : BROWSER_OUTPUT: Cycle 1(4): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:28 INFO - 2015-10-30 01:20:28,465 DEBUG : BROWSER_OUTPUT: RSS: Main: 177627136
01:20:28 INFO - 2015-10-30 01:20:28,465 DEBUG : BROWSER_OUTPUT:
01:20:29 INFO - 2015-10-30 01:20:29,045 DEBUG : BROWSER_OUTPUT: Cycle 1(5): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:29 INFO - 2015-10-30 01:20:29,620 DEBUG : BROWSER_OUTPUT: RSS: Main: 178401280
01:20:29 INFO - 2015-10-30 01:20:29,621 DEBUG : BROWSER_OUTPUT:
01:20:30 INFO - 2015-10-30 01:20:30,192 DEBUG : BROWSER_OUTPUT: Cycle 1(6): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:30 INFO - 2015-10-30 01:20:30,765 DEBUG : BROWSER_OUTPUT: RSS: Main: 177889280
01:20:30 INFO - 2015-10-30 01:20:30,766 DEBUG : BROWSER_OUTPUT:
01:20:31 INFO - 2015-10-30 01:20:31,338 DEBUG : BROWSER_OUTPUT: Cycle 1(7): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:31 INFO - 2015-10-30 01:20:31,919 DEBUG : BROWSER_OUTPUT: RSS: Main: 180801536
01:20:31 INFO - 2015-10-30 01:20:31,919 DEBUG : BROWSER_OUTPUT:
01:20:32 INFO - 2015-10-30 01:20:32,484 DEBUG : BROWSER_OUTPUT: Cycle 1(8): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:33 INFO - 2015-10-30 01:20:33,065 DEBUG : BROWSER_OUTPUT: RSS: Main: 183078912
01:20:33 INFO - 2015-10-30 01:20:33,065 DEBUG : BROWSER_OUTPUT:
01:20:33 INFO - 2015-10-30 01:20:33,651 DEBUG : BROWSER_OUTPUT: Cycle 1(9): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:34 INFO - 2015-10-30 01:20:34,244 DEBUG : BROWSER_OUTPUT: RSS: Main: 185729024
01:20:34 INFO - 2015-10-30 01:20:34,244 DEBUG : BROWSER_OUTPUT:
01:20:34 INFO - 2015-10-30 01:20:34,824 DEBUG : BROWSER_OUTPUT: Cycle 1(10): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:35 INFO - 2015-10-30 01:20:35,414 DEBUG : BROWSER_OUTPUT: RSS: Main: 185729024
01:20:35 INFO - 2015-10-30 01:20:35,414 DEBUG : BROWSER_OUTPUT:
01:20:35 INFO - 2015-10-30 01:20:35,994 DEBUG : BROWSER_OUTPUT: Cycle 1(11): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:36 INFO - 2015-10-30 01:20:36,580 DEBUG : BROWSER_OUTPUT: RSS: Main: 184266752
01:20:36 INFO - 2015-10-30 01:20:36,580 DEBUG : BROWSER_OUTPUT:
01:20:37 INFO - 2015-10-30 01:20:37,160 DEBUG : BROWSER_OUTPUT: Cycle 1(12): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:37 INFO - 2015-10-30 01:20:37,742 DEBUG : BROWSER_OUTPUT: RSS: Main: 184328192
01:20:37 INFO - 2015-10-30 01:20:37,743 DEBUG : BROWSER_OUTPUT:
01:20:38 INFO - 2015-10-30 01:20:38,327 DEBUG : BROWSER_OUTPUT: Cycle 1(13): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:38 INFO - 2015-10-30 01:20:38,914 DEBUG : BROWSER_OUTPUT: RSS: Main: 183427072
01:20:38 INFO - 2015-10-30 01:20:38,914 DEBUG : BROWSER_OUTPUT:
01:20:39 INFO - 2015-10-30 01:20:39,493 DEBUG : BROWSER_OUTPUT: Cycle 1(14): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:40 INFO - 2015-10-30 01:20:40,075 DEBUG : BROWSER_OUTPUT: RSS: Main: 183734272
01:20:40 INFO - 2015-10-30 01:20:40,076 DEBUG : BROWSER_OUTPUT:
01:20:40 INFO - 2015-10-30 01:20:40,619 DEBUG : BROWSER_OUTPUT: Cycle 1(15): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:41 INFO - 2015-10-30 01:20:41,201 DEBUG : BROWSER_OUTPUT: RSS: Main: 183521280
01:20:41 INFO - 2015-10-30 01:20:41,202 DEBUG : BROWSER_OUTPUT:
01:20:41 INFO - 2015-10-30 01:20:41,781 DEBUG : BROWSER_OUTPUT: Cycle 1(16): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:42 INFO - 2015-10-30 01:20:42,356 DEBUG : BROWSER_OUTPUT: RSS: Main: 183009280
01:20:42 INFO - 2015-10-30 01:20:42,356 DEBUG : BROWSER_OUTPUT:
01:20:42 INFO - 2015-10-30 01:20:42,904 DEBUG : BROWSER_OUTPUT: Cycle 1(17): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:43 INFO - 2015-10-30 01:20:43,485 DEBUG : BROWSER_OUTPUT: RSS: Main: 181112832
01:20:43 INFO - 2015-10-30 01:20:43,485 DEBUG : BROWSER_OUTPUT:
01:20:44 INFO - 2015-10-30 01:20:44,065 DEBUG : BROWSER_OUTPUT: Cycle 1(18): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:44 INFO - 2015-10-30 01:20:44,647 DEBUG : BROWSER_OUTPUT: RSS: Main: 175050752
01:20:44 INFO - 2015-10-30 01:20:44,647 DEBUG : BROWSER_OUTPUT:
01:20:45 INFO - 2015-10-30 01:20:45,219 DEBUG : BROWSER_OUTPUT: Cycle 1(19): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:45 INFO - 2015-10-30 01:20:45,806 DEBUG : BROWSER_OUTPUT: RSS: Main: 177278976
01:20:45 INFO - 2015-10-30 01:20:45,806 DEBUG : BROWSER_OUTPUT:
01:20:46 INFO - 2015-10-30 01:20:46,390 DEBUG : BROWSER_OUTPUT: Cycle 1(20): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:46 INFO - 2015-10-30 01:20:46,973 DEBUG : BROWSER_OUTPUT: RSS: Main: 174940160
01:20:46 INFO - 2015-10-30 01:20:46,973 DEBUG : BROWSER_OUTPUT:
01:20:47 INFO - 2015-10-30 01:20:47,545 DEBUG : BROWSER_OUTPUT: Cycle 1(21): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:48 INFO - 2015-10-30 01:20:48,132 DEBUG : BROWSER_OUTPUT: RSS: Main: 175742976
01:20:48 INFO - 2015-10-30 01:20:48,132 DEBUG : BROWSER_OUTPUT:
01:20:48 INFO - 2015-10-30 01:20:48,712 DEBUG : BROWSER_OUTPUT: Cycle 1(22): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:49 INFO - 2015-10-30 01:20:49,286 DEBUG : BROWSER_OUTPUT: RSS: Main: 176418816
01:20:49 INFO - 2015-10-30 01:20:49,287 DEBUG : BROWSER_OUTPUT:
01:20:49 INFO - 2015-10-30 01:20:49,866 DEBUG : BROWSER_OUTPUT: Cycle 1(23): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:50 INFO - 2015-10-30 01:20:50,448 DEBUG : BROWSER_OUTPUT: RSS: Main: 176521216
01:20:50 INFO - 2015-10-30 01:20:50,448 DEBUG : BROWSER_OUTPUT:
01:20:50 INFO - 2015-10-30 01:20:50,993 DEBUG : BROWSER_OUTPUT: Cycle 1(24): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:51 INFO - 2015-10-30 01:20:51,575 DEBUG : BROWSER_OUTPUT: RSS: Main: 175362048
01:20:51 INFO - 2015-10-30 01:20:51,575 DEBUG : BROWSER_OUTPUT:
01:20:52 INFO - 2015-10-30 01:20:52,155 DEBUG : BROWSER_OUTPUT: Cycle 1(25): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html)
01:20:52 INFO - 2015-10-30 01:20:52,405 DEBUG : BROWSER_OUTPUT: RSS: Main: 182370304
01:20:52 INFO - 2015-10-30 01:20:52,405 DEBUG : BROWSER_OUTPUT:
01:20:52 INFO - 2015-10-30 01:20:52,405 DEBUG : BROWSER_OUTPUT: __start_tp_report
01:20:52 INFO - 2015-10-30 01:20:52,405 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load
01:20:52 INFO - 2015-10-30 01:20:52,405 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load_details
01:20:52 INFO - 2015-10-30 01:20:52,405 DEBUG : BROWSER_OUTPUT: |i|pagename|runs|
01:20:52 INFO - 2015-10-30 01:20:52,406 DEBUG : BROWSER_OUTPUT: |0;dhtml.html;864;909;852;918;914;921;923;923;855;924;921;926;958;931;923;861;938;992;928;1000;929;922;921;993;923
01:20:52 INFO - 2015-10-30 01:20:52,406 DEBUG : BROWSER_OUTPUT: |1;tablemutation.html;203;196;197;196;195;194;195;195;203;199;197;196;198;196;195;198;197;196;196;196;198;197;197;196;196
01:20:52 INFO - 2015-10-30 01:20:52,406 DEBUG : BROWSER_OUTPUT: __end_tp_report
01:20:52 INFO - 2015-10-30 01:20:52,406 DEBUG : BROWSER_OUTPUT: __start_cc_report
01:20:52 INFO - 2015-10-30 01:20:52,406 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_cycle_collect,5361
01:20:52 INFO - 2015-10-30 01:20:52,406 DEBUG : BROWSER_OUTPUT: __end_cc_report
01:20:52 INFO - 2015-10-30 01:20:52,406 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193252404__endTimestamp
01:20:52 INFO - 2015-10-30 01:20:52,407 DEBUG : BROWSER_OUTPUT:
01:20:52 INFO - 2015-10-30 01:20:52,407 DEBUG : BROWSER_OUTPUT: ------- Summary: start -------
01:20:52 INFO - 2015-10-30 01:20:52,408 DEBUG : BROWSER_OUTPUT: Number of tests: 2
01:20:52 INFO - 2015-10-30 01:20:52,408 DEBUG : BROWSER_OUTPUT:
01:20:52 INFO - 2015-10-30 01:20:52,408 DEBUG : BROWSER_OUTPUT: [#0] dhtml.html Cycles:25 Average:922.76 Median:923.00 stddev:37.90 (4.1%) stddev-sans-first:36.64
01:20:52 INFO - 2015-10-30 01:20:52,409 DEBUG : BROWSER_OUTPUT: Values: 864.0 909.0 852.0 918.0 914.0 921.0 923.0 923.0 855.0 924.0 921.0 926.0 958.0 931.0 923.0 861.0 938.0 992.0 928.0 1000.0 929.0 922.0 921.0 993.0 923.0
01:20:52 INFO - 2015-10-30 01:20:52,409 DEBUG : BROWSER_OUTPUT:
01:20:52 INFO - 2015-10-30 01:20:52,409 DEBUG : BROWSER_OUTPUT: [#1] tablemutation.html Cycles:25 Average:196.88 Median:196.00 stddev:2.17 (1.1%) stddev-sans-first:1.79
01:20:52 INFO - 2015-10-30 01:20:52,409 DEBUG : BROWSER_OUTPUT: Values: 203.0 196.0 197.0 196.0 195.0 194.0 195.0 195.0 203.0 199.0 197.0 196.0 198.0 196.0 195.0 198.0 197.0 196.0 196.0 196.0 198.0 197.0 197.0 196.0 196.0
01:20:52 INFO - 2015-10-30 01:20:52,409 DEBUG : BROWSER_OUTPUT: -------- Summary: end --------
01:20:52 INFO - 2015-10-30 01:20:52,409 DEBUG : BROWSER_OUTPUT:
01:20:52 INFO - 2015-10-30 01:20:52,969 INFO : Browser exited with error code: 0
01:20:52 INFO - 2015-10-30 01:20:52,985 INFO : Completed test a11yr (00:01:29)
01:20:52 INFO - 2015-10-30 01:20:52,985 INFO : Starting test ts_paint
01:20:52 INFO - 2015-10-30 01:20:52,985 DEBUG : operating with platform_type : linux_
01:20:52 INFO - 2015-10-30 01:20:52,985 INFO : Initialising browser for ts_paint test...
01:20:52 INFO - 2015-10-30 01:20:52,991 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/getInfo.html
01:20:56 INFO - 2015-10-30 01:20:56,611 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
01:20:56 INFO - 2015-10-30 01:20:56,611 DEBUG : BROWSER_OUTPUT: colorDepth:24
01:20:56 INFO - 2015-10-30 01:20:56,611 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697
01:20:56 INFO - 2015-10-30 01:20:56,611 DEBUG : BROWSER_OUTPUT: __metrics
01:20:56 INFO - 2015-10-30 01:20:56,789 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,996 INFO : Browser initialized.
01:20:57 INFO - 2015-10-30 01:20:57,996 INFO : Running cycle 1/20 for ts_paint test...
01:20:57 INFO - 2015-10-30 01:20:57,996 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html
01:20:59 INFO - 2015-10-30 01:20:59,409 DEBUG : BROWSER_OUTPUT: __start_report1408__end_report
01:20:59 INFO - 2015-10-30 01:20:59,409 DEBUG : BROWSER_OUTPUT:
01:20:59 INFO - 2015-10-30 01:20:59,417 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193259413__endTimestamp
01:21:00 INFO - 2015-10-30 01:21:00,284 INFO : Browser exited with error code: 0
01:21:00 INFO - 2015-10-30 01:21:00,286 INFO : Running cycle 2/20 for ts_paint test...
01:21:00 INFO - 2015-10-30 01:21:00,286 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html
01:21:01 INFO - 2015-10-30 01:21:01,197 DEBUG : BROWSER_OUTPUT: __start_report907__end_report
01:21:01 INFO - 2015-10-30 01:21:01,197 DEBUG : BROWSER_OUTPUT:
01:21:01 INFO - 2015-10-30 01:21:01,204 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193261202__endTimestamp
01:21:01 INFO - 2015-10-30 01:21:01,873 INFO : Browser exited with error code: 0
01:21:01 INFO - 2015-10-30 01:21:01,875 INFO : Running cycle 3/20 for ts_paint test...
01:21:01 INFO - 2015-10-30 01:21:01,875 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html
01:21:02 INFO - 2015-10-30 01:21:02,808 DEBUG : BROWSER_OUTPUT: __start_report929__end_report
01:21:02 INFO - 2015-10-30 01:21:02,808 DEBUG : BROWSER_OUTPUT:
01:21:02 INFO - 2015-10-30 01:21:02,815 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193262814__endTimestamp
01:21:03 INFO - 2015-10-30 01:21:03,693 INFO : Browser exited with error code: 0
01:21:03 INFO - 2015-10-30 01:21:03,695 INFO : Running cycle 4/20 for ts_paint test...
01:21:03 INFO - 2015-10-30 01:21:03,695 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html
01:21:04 INFO - 2015-10-30 01:21:04,607 DEBUG : BROWSER_OUTPUT: __start_report906__end_report
01:21:04 INFO - 2015-10-30 01:21:04,607 DEBUG : BROWSER_OUTPUT:
01:21:04 INFO - 2015-10-30 01:21:04,615 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193264611__endTimestamp
01:21:05 INFO - 2015-10-30 01:21:05,497 INFO : Browser exited with error code: 0
01:21:05 INFO - 2015-10-30 01:21:05,499 INFO : Running cycle 5/20 for ts_paint test...
01:21:05 INFO - 2015-10-30 01:21:05,499 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html
01:21:06 INFO - 2015-10-30 01:21:06,419 DEBUG : BROWSER_OUTPUT: __start_report924__end_report
01:21:06 INFO - 2015-10-30 01:21:06,420 DEBUG : BROWSER_OUTPUT:
01:21:06 INFO - 2015-10-30 01:21:06,427 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193266426__endTimestamp
01:21:07 INFO - 2015-10-30 01:21:07,285 INFO : Browser exited with error code: 0
01:21:07 INFO - 2015-10-30 01:21:07,287 INFO : Running cycle 6/20 for ts_paint test...
01:21:07 INFO - 2015-10-30 01:21:07,287 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html
01:21:08 INFO - 2015-10-30 01:21:08,236 DEBUG : BROWSER_OUTPUT: __start_report948__end_report
01:21:08 INFO - 2015-10-30 01:21:08,236 DEBUG : BROWSER_OUTPUT:
01:21:08 INFO - 2015-10-30 01:21:08,252 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193268246__endTimestamp
01:21:09 INFO - 2015-10-30 01:21:09,137 INFO : Browser exited with error code: 0
01:21:09 INFO - 2015-10-30 01:21:09,139 INFO : Running cycle 7/20 for ts_paint test...
01:21:09 INFO - 2015-10-30 01:21:09,139 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html
01:21:10 INFO - 2015-10-30 01:21:10,032 DEBUG : BROWSER_OUTPUT: __start_report900__end_report
01:21:10 INFO - 2015-10-30 01:21:10,032 DEBUG : BROWSER_OUTPUT:
01:21:10 INFO - 2015-10-30 01:21:10,040 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193270040__endTimestamp
01:21:10 INFO - 2015-10-30 01:21:10,777 INFO : Browser exited with error code: 0
01:21:10 INFO - 2015-10-30 01:21:10,778 INFO : Running cycle 8/20 for ts_paint test...
01:21:10 INFO - 2015-10-30 01:21:10,778 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html
01:21:11 INFO - 2015-10-30 01:21:11,677 DEBUG : BROWSER_OUTPUT: __start_report901__end_report
01:21:11 INFO - 2015-10-30 01:21:11,678 DEBUG : BROWSER_OUTPUT:
01:21:11 INFO - 2015-10-30 01:21:11,685 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193271684__endTimestamp
01:21:12 INFO - 2015-10-30 01:21:12,466 INFO : Browser exited with error code: 0
01:21:12 INFO - 2015-10-30 01:21:12,467 INFO : Running cycle 9/20 for ts_paint test...
01:21:12 INFO - 2015-10-30 01:21:12,467 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html
01:21:13 INFO - 2015-10-30 01:21:13,356 DEBUG : BROWSER_OUTPUT: __start_report888__end_report
01:21:13 INFO - 2015-10-30 01:21:13,356 DEBUG : BROWSER_OUTPUT:
01:21:13 INFO - 2015-10-30 01:21:13,363 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193273363__endTimestamp
01:21:14 INFO - 2015-10-30 01:21:14,104 INFO : Browser exited with error code: 0
01:21:14 INFO - 2015-10-30 01:21:14,106 INFO : Running cycle 10/20 for ts_paint test...
01:21:14 INFO - 2015-10-30 01:21:14,106 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html
01:21:15 INFO - 2015-10-30 01:21:15,062 DEBUG : BROWSER_OUTPUT: __start_report959__end_report
01:21:15 INFO - 2015-10-30 01:21:15,062 DEBUG : BROWSER_OUTPUT:
01:21:15 INFO - 2015-10-30 01:21:15,070 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193275068__endTimestamp
01:21:15 INFO - 2015-10-30 01:21:15,929 INFO : Browser exited with error code: 0
01:21:15 INFO - 2015-10-30 01:21:15,931 INFO : Running cycle 11/20 for ts_paint test...
01:21:15 INFO - 2015-10-30 01:21:15,931 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html
01:21:16 INFO - 2015-10-30 01:21:16,885 DEBUG : BROWSER_OUTPUT: __start_report945__end_report
01:21:16 INFO - 2015-10-30 01:21:16,885 DEBUG : BROWSER_OUTPUT:
01:21:16 INFO - 2015-10-30 01:21:16,901 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193276900__endTimestamp
01:21:17 INFO - 2015-10-30 01:21:17,773 INFO : Browser exited with error code: 0
01:21:17 INFO - 2015-10-30 01:21:17,775 INFO : Running cycle 12/20 for ts_paint test...
01:21:17 INFO - 2015-10-30 01:21:17,775 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html
01:21:18 INFO - 2015-10-30 01:21:18,675 DEBUG : BROWSER_OUTPUT: __start_report900__end_report
01:21:18 INFO - 2015-10-30 01:21:18,675 DEBUG : BROWSER_OUTPUT:
01:21:18 INFO - 2015-10-30 01:21:18,691 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193278689__endTimestamp
01:21:19 INFO - 2015-10-30 01:21:19,462 INFO : Browser exited with error code: 0
01:21:19 INFO - 2015-10-30 01:21:19,463 INFO : Running cycle 13/20 for ts_paint test...
01:21:19 INFO - 2015-10-30 01:21:19,463 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html
01:21:20 INFO - 2015-10-30 01:21:20,411 DEBUG : BROWSER_OUTPUT: __start_report944__end_report
01:21:20 INFO - 2015-10-30 01:21:20,411 DEBUG : BROWSER_OUTPUT:
01:21:20 INFO - 2015-10-30 01:21:20,419 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193280416__endTimestamp
01:21:21 INFO - 2015-10-30 01:21:21,229 INFO : Browser exited with error code: 0
01:21:21 INFO - 2015-10-30 01:21:21,231 INFO : Running cycle 14/20 for ts_paint test...
01:21:21 INFO - 2015-10-30 01:21:21,231 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html
01:21:22 INFO - 2015-10-30 01:21:22,163 DEBUG : BROWSER_OUTPUT: __start_report924__end_report
01:21:22 INFO - 2015-10-30 01:21:22,163 DEBUG : BROWSER_OUTPUT:
01:21:22 INFO - 2015-10-30 01:21:22,183 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193282179__endTimestamp
01:21:23 INFO - 2015-10-30 01:21:23,121 INFO : Browser exited with error code: 0
01:21:23 INFO - 2015-10-30 01:21:23,123 INFO : Running cycle 15/20 for ts_paint test...
01:21:23 INFO - 2015-10-30 01:21:23,123 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html
01:21:24 INFO - 2015-10-30 01:21:24,111 DEBUG : BROWSER_OUTPUT: __start_report980__end_report
01:21:24 INFO - 2015-10-30 01:21:24,111 DEBUG : BROWSER_OUTPUT:
01:21:24 INFO - 2015-10-30 01:21:24,114 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193284114__endTimestamp
01:21:24 INFO - 2015-10-30 01:21:24,911 INFO : Browser exited with error code: 0
01:21:24 INFO - 2015-10-30 01:21:24,912 INFO : Running cycle 16/20 for ts_paint test...
01:21:24 INFO - 2015-10-30 01:21:24,913 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html
01:21:25 INFO - 2015-10-30 01:21:25,833 DEBUG : BROWSER_OUTPUT: __start_report914__end_report
01:21:25 INFO - 2015-10-30 01:21:25,833 DEBUG : BROWSER_OUTPUT:
01:21:25 INFO - 2015-10-30 01:21:25,849 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193285841__endTimestamp
01:21:26 INFO - 2015-10-30 01:21:26,600 INFO : Browser exited with error code: 0
01:21:26 INFO - 2015-10-30 01:21:26,601 INFO : Running cycle 17/20 for ts_paint test...
01:21:26 INFO - 2015-10-30 01:21:26,601 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html
01:21:27 INFO - 2015-10-30 01:21:27,553 DEBUG : BROWSER_OUTPUT: __start_report947__end_report
01:21:27 INFO - 2015-10-30 01:21:27,553 DEBUG : BROWSER_OUTPUT:
01:21:27 INFO - 2015-10-30 01:21:27,561 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193287558__endTimestamp
01:21:28 INFO - 2015-10-30 01:21:28,489 INFO : Browser exited with error code: 0
01:21:28 INFO - 2015-10-30 01:21:28,491 INFO : Running cycle 18/20 for ts_paint test...
01:21:28 INFO - 2015-10-30 01:21:28,491 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html
01:21:29 INFO - 2015-10-30 01:21:29,411 DEBUG : BROWSER_OUTPUT: __start_report914__end_report
01:21:29 INFO - 2015-10-30 01:21:29,411 DEBUG : BROWSER_OUTPUT:
01:21:29 INFO - 2015-10-30 01:21:29,427 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193289425__endTimestamp
01:21:30 INFO - 2015-10-30 01:21:30,385 INFO : Browser exited with error code: 0
01:21:30 INFO - 2015-10-30 01:21:30,387 INFO : Running cycle 19/20 for ts_paint test...
01:21:30 INFO - 2015-10-30 01:21:30,387 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html
01:21:31 INFO - 2015-10-30 01:21:31,319 DEBUG : BROWSER_OUTPUT: __start_report932__end_report
01:21:31 INFO - 2015-10-30 01:21:31,319 DEBUG : BROWSER_OUTPUT:
01:21:31 INFO - 2015-10-30 01:21:31,335 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193291328__endTimestamp
01:21:32 INFO - 2015-10-30 01:21:32,209 INFO : Browser exited with error code: 0
01:21:32 INFO - 2015-10-30 01:21:32,211 INFO : Running cycle 20/20 for ts_paint test...
01:21:32 INFO - 2015-10-30 01:21:32,211 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html
01:21:33 INFO - 2015-10-30 01:21:33,142 DEBUG : BROWSER_OUTPUT: __start_report924__end_report
01:21:33 INFO - 2015-10-30 01:21:33,143 DEBUG : BROWSER_OUTPUT:
01:21:33 INFO - 2015-10-30 01:21:33,150 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193293149__endTimestamp
01:21:34 INFO - 2015-10-30 01:21:34,113 INFO : Browser exited with error code: 0
01:21:34 INFO - 2015-10-30 01:21:34,132 INFO : Completed test ts_paint (00:00:41)
01:21:34 INFO - 2015-10-30 01:21:34,132 INFO : Starting test tpaint
01:21:34 INFO - 2015-10-30 01:21:34,132 DEBUG : operating with platform_type : linux_
01:21:34 INFO - 2015-10-30 01:21:34,132 INFO : Initialising browser for tpaint test...
01:21:34 INFO - 2015-10-30 01:21:34,139 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpyxWdBu/profile http://localhost/getInfo.html
01:21:37 INFO - 2015-10-30 01:21:37,676 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
01:21:37 INFO - 2015-10-30 01:21:37,677 DEBUG : BROWSER_OUTPUT: colorDepth:24
01:21:37 INFO - 2015-10-30 01:21:37,677 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697
01:21:37 INFO - 2015-10-30 01:21:37,677 DEBUG : BROWSER_OUTPUT: __metrics
01:21:37 INFO - 2015-10-30 01:21:37,894 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:39 INFO - 2015-10-30 01:21:39,207 INFO : Browser initialized.
01:21:39 INFO - 2015-10-30 01:21:39,207 INFO : Running cycle 1/1 for tpaint test...
01:21:39 INFO - 2015-10-30 01:21:39,208 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpyxWdBu/profile file:///builds/slave/test-pgo/build/tests/talos/talos/startup_test/tpaint.html?auto=1
01:22:04 INFO - 2015-10-30 01:22:04,159 DEBUG : BROWSER_OUTPUT: __start_report154.4649999999997|154.54499999999985|155.5650000000005|155.71999999999753|156.51000000000113|159.875|161.10999999999876|161.95000000000073|167.01999999999998|172.6800000000003|173.51499999999942|174.47000000000116|175.65499999999884|176.26999999999862|179.33500000000095|183.79499999999825|187.35499999999956|190.1449999999968|204.45000000000073|249.59000000000015__end_report__startTimestamp1446193324156__endTimestamp
01:22:04 INFO - 2015-10-30 01:22:04,159 DEBUG : BROWSER_OUTPUT: openingTimes=154.54499999999985,155.5650000000005,155.71999999999753,156.51000000000113,159.875,161.10999999999876,161.95000000000073,167.01999999999998,172.6800000000003,173.51499999999942,174.47000000000116,175.65499999999884,176.26999999999862,179.33500000000095,183.79499999999825,187.35499999999956,190.1449999999968,204.45000000000073,249.59000000000015
01:22:04 INFO - 2015-10-30 01:22:04,159 DEBUG : BROWSER_OUTPUT: avgOpenTime:174.70
01:22:04 INFO - 2015-10-30 01:22:04,159 DEBUG : BROWSER_OUTPUT: minOpenTime:154.46
01:22:04 INFO - 2015-10-30 01:22:04,159 DEBUG : BROWSER_OUTPUT: maxOpenTime:249.59
01:22:04 INFO - 2015-10-30 01:22:04,159 DEBUG : BROWSER_OUTPUT: medOpenTime:173.09749999999985
01:22:04 INFO - 2015-10-30 01:22:04,159 DEBUG : BROWSER_OUTPUT: __xulWinOpenTime:173.09749999999985
01:22:04 INFO - 2015-10-30 01:22:04,978 INFO : Browser exited with error code: 0
01:22:04 INFO - 2015-10-30 01:22:04,994 INFO : Completed test tpaint (00:00:30)
01:22:04 INFO - 2015-10-30 01:22:04,994 INFO : Starting test sessionrestore
01:22:04 INFO - 2015-10-30 01:22:04,994 DEBUG : operating with platform_type : linux_
01:22:04 INFO - 2015-10-30 01:22:04,994 INFO : Initialising browser for sessionrestore test...
01:22:05 INFO - 2015-10-30 01:22:05,001 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpMnKcoU/profile http://localhost/getInfo.html
01:22:08 INFO - 2015-10-30 01:22:08,846 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
01:22:08 INFO - 2015-10-30 01:22:08,846 DEBUG : BROWSER_OUTPUT: colorDepth:24
01:22:08 INFO - 2015-10-30 01:22:08,846 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1151/811
01:22:08 INFO - 2015-10-30 01:22:08,846 DEBUG : BROWSER_OUTPUT: __metrics
01:22:09 INFO - 2015-10-30 01:22:09,011 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:10 INFO - 2015-10-30 01:22:10,369 INFO : Browser initialized.
01:22:10 INFO - 2015-10-30 01:22:10,370 INFO : Running cycle 1/10 for sessionrestore test...
01:22:10 INFO - 2015-10-30 01:22:10,370 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpMnKcoU/profile/sessionstore.js
01:22:10 INFO - 2015-10-30 01:22:10,372 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpMnKcoU/profile http://localhost/startup_test/sessionrestore/index.html
01:22:13 INFO - 2015-10-30 01:22:13,952 DEBUG : BROWSER_OUTPUT: __start_report1734__end_report
01:22:13 INFO - 2015-10-30 01:22:13,952 DEBUG : BROWSER_OUTPUT:
01:22:13 INFO - 2015-10-30 01:22:13,952 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193333951__endTimestamp
01:22:13 INFO - 2015-10-30 01:22:13,952 DEBUG : BROWSER_OUTPUT:
01:22:15 INFO - 2015-10-30 01:22:15,409 INFO : Browser exited with error code: 0
01:22:15 INFO - 2015-10-30 01:22:15,411 INFO : Running cycle 2/10 for sessionrestore test...
01:22:15 INFO - 2015-10-30 01:22:15,411 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpMnKcoU/profile/sessionstore.js
01:22:15 INFO - 2015-10-30 01:22:15,413 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpMnKcoU/profile http://localhost/startup_test/sessionrestore/index.html
01:22:17 INFO - 2015-10-30 01:22:17,940 DEBUG : BROWSER_OUTPUT: __start_report1465__end_report
01:22:17 INFO - 2015-10-30 01:22:17,940 DEBUG : BROWSER_OUTPUT:
01:22:17 INFO - 2015-10-30 01:22:17,940 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193337938__endTimestamp
01:22:17 INFO - 2015-10-30 01:22:17,940 DEBUG : BROWSER_OUTPUT:
01:22:19 INFO - 2015-10-30 01:22:19,625 INFO : Browser exited with error code: 0
01:22:19 INFO - 2015-10-30 01:22:19,627 INFO : Running cycle 3/10 for sessionrestore test...
01:22:19 INFO - 2015-10-30 01:22:19,627 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpMnKcoU/profile/sessionstore.js
01:22:19 INFO - 2015-10-30 01:22:19,629 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpMnKcoU/profile http://localhost/startup_test/sessionrestore/index.html
01:22:22 INFO - 2015-10-30 01:22:22,158 DEBUG : BROWSER_OUTPUT: __start_report1446__end_report
01:22:22 INFO - 2015-10-30 01:22:22,159 DEBUG : BROWSER_OUTPUT:
01:22:22 INFO - 2015-10-30 01:22:22,159 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193342155__endTimestamp
01:22:22 INFO - 2015-10-30 01:22:22,159 DEBUG : BROWSER_OUTPUT:
01:22:23 INFO - 2015-10-30 01:22:23,837 INFO : Browser exited with error code: 0
01:22:23 INFO - 2015-10-30 01:22:23,839 INFO : Running cycle 4/10 for sessionrestore test...
01:22:23 INFO - 2015-10-30 01:22:23,839 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpMnKcoU/profile/sessionstore.js
01:22:23 INFO - 2015-10-30 01:22:23,841 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpMnKcoU/profile http://localhost/startup_test/sessionrestore/index.html
01:22:26 INFO - 2015-10-30 01:22:26,448 DEBUG : BROWSER_OUTPUT: __start_report1491__end_report
01:22:26 INFO - 2015-10-30 01:22:26,449 DEBUG : BROWSER_OUTPUT:
01:22:26 INFO - 2015-10-30 01:22:26,449 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193346445__endTimestamp
01:22:26 INFO - 2015-10-30 01:22:26,449 DEBUG : BROWSER_OUTPUT:
01:22:28 INFO - 2015-10-30 01:22:28,125 INFO : Browser exited with error code: 0
01:22:28 INFO - 2015-10-30 01:22:28,127 INFO : Running cycle 5/10 for sessionrestore test...
01:22:28 INFO - 2015-10-30 01:22:28,127 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpMnKcoU/profile/sessionstore.js
01:22:28 INFO - 2015-10-30 01:22:28,129 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpMnKcoU/profile http://localhost/startup_test/sessionrestore/index.html
01:22:30 INFO - 2015-10-30 01:22:30,662 DEBUG : BROWSER_OUTPUT: __start_report1469__end_report
01:22:30 INFO - 2015-10-30 01:22:30,663 DEBUG : BROWSER_OUTPUT:
01:22:30 INFO - 2015-10-30 01:22:30,663 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193350660__endTimestamp
01:22:30 INFO - 2015-10-30 01:22:30,663 DEBUG : BROWSER_OUTPUT:
01:22:32 INFO - 2015-10-30 01:22:32,369 INFO : Browser exited with error code: 0
01:22:32 INFO - 2015-10-30 01:22:32,371 INFO : Running cycle 6/10 for sessionrestore test...
01:22:32 INFO - 2015-10-30 01:22:32,371 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpMnKcoU/profile/sessionstore.js
01:22:32 INFO - 2015-10-30 01:22:32,373 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpMnKcoU/profile http://localhost/startup_test/sessionrestore/index.html
01:22:34 INFO - 2015-10-30 01:22:34,902 DEBUG : BROWSER_OUTPUT: __start_report1469__end_report
01:22:34 INFO - 2015-10-30 01:22:34,902 DEBUG : BROWSER_OUTPUT:
01:22:34 INFO - 2015-10-30 01:22:34,902 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193354901__endTimestamp
01:22:34 INFO - 2015-10-30 01:22:34,902 DEBUG : BROWSER_OUTPUT:
01:22:36 INFO - 2015-10-30 01:22:36,657 INFO : Browser exited with error code: 0
01:22:36 INFO - 2015-10-30 01:22:36,659 INFO : Running cycle 7/10 for sessionrestore test...
01:22:36 INFO - 2015-10-30 01:22:36,659 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpMnKcoU/profile/sessionstore.js
01:22:36 INFO - 2015-10-30 01:22:36,661 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpMnKcoU/profile http://localhost/startup_test/sessionrestore/index.html
01:22:39 INFO - 2015-10-30 01:22:39,224 DEBUG : BROWSER_OUTPUT: __start_report1494__end_report
01:22:39 INFO - 2015-10-30 01:22:39,224 DEBUG : BROWSER_OUTPUT:
01:22:39 INFO - 2015-10-30 01:22:39,224 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193359222__endTimestamp
01:22:39 INFO - 2015-10-30 01:22:39,224 DEBUG : BROWSER_OUTPUT:
01:22:40 INFO - 2015-10-30 01:22:40,969 INFO : Browser exited with error code: 0
01:22:40 INFO - 2015-10-30 01:22:40,971 INFO : Running cycle 8/10 for sessionrestore test...
01:22:40 INFO - 2015-10-30 01:22:40,971 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpMnKcoU/profile/sessionstore.js
01:22:40 INFO - 2015-10-30 01:22:40,973 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpMnKcoU/profile http://localhost/startup_test/sessionrestore/index.html
01:22:43 INFO - 2015-10-30 01:22:43,560 DEBUG : BROWSER_OUTPUT: __start_report1490__end_report
01:22:43 INFO - 2015-10-30 01:22:43,561 DEBUG : BROWSER_OUTPUT:
01:22:43 INFO - 2015-10-30 01:22:43,561 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193363560__endTimestamp
01:22:43 INFO - 2015-10-30 01:22:43,561 DEBUG : BROWSER_OUTPUT:
01:22:45 INFO - 2015-10-30 01:22:45,238 INFO : Browser exited with error code: 0
01:22:45 INFO - 2015-10-30 01:22:45,239 INFO : Running cycle 9/10 for sessionrestore test...
01:22:45 INFO - 2015-10-30 01:22:45,240 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpMnKcoU/profile/sessionstore.js
01:22:45 INFO - 2015-10-30 01:22:45,242 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpMnKcoU/profile http://localhost/startup_test/sessionrestore/index.html
01:22:47 INFO - 2015-10-30 01:22:47,773 DEBUG : BROWSER_OUTPUT: __start_report1453__end_report
01:22:47 INFO - 2015-10-30 01:22:47,773 DEBUG : BROWSER_OUTPUT:
01:22:47 INFO - 2015-10-30 01:22:47,773 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193367771__endTimestamp
01:22:47 INFO - 2015-10-30 01:22:47,773 DEBUG : BROWSER_OUTPUT:
01:22:49 INFO - 2015-10-30 01:22:49,525 INFO : Browser exited with error code: 0
01:22:49 INFO - 2015-10-30 01:22:49,527 INFO : Running cycle 10/10 for sessionrestore test...
01:22:49 INFO - 2015-10-30 01:22:49,527 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpMnKcoU/profile/sessionstore.js
01:22:49 INFO - 2015-10-30 01:22:49,529 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpMnKcoU/profile http://localhost/startup_test/sessionrestore/index.html
01:22:52 INFO - 2015-10-30 01:22:52,060 DEBUG : BROWSER_OUTPUT: __start_report1482__end_report
01:22:52 INFO - 2015-10-30 01:22:52,060 DEBUG : BROWSER_OUTPUT:
01:22:52 INFO - 2015-10-30 01:22:52,060 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193372059__endTimestamp
01:22:52 INFO - 2015-10-30 01:22:52,060 DEBUG : BROWSER_OUTPUT:
01:22:53 INFO - 2015-10-30 01:22:53,789 INFO : Browser exited with error code: 0
01:22:53 INFO - 2015-10-30 01:22:53,803 INFO : Completed test sessionrestore (00:00:48)
01:22:53 INFO - 2015-10-30 01:22:53,803 INFO : Starting test sessionrestore_no_auto_restore
01:22:53 INFO - 2015-10-30 01:22:53,803 DEBUG : operating with platform_type : linux_
01:22:53 INFO - 2015-10-30 01:22:53,803 INFO : Initialising browser for sessionrestore_no_auto_restore test...
01:22:53 INFO - 2015-10-30 01:22:53,809 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmp6YRPR7/profile http://localhost/getInfo.html
01:22:57 INFO - 2015-10-30 01:22:57,527 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
01:22:57 INFO - 2015-10-30 01:22:57,527 DEBUG : BROWSER_OUTPUT: colorDepth:24
01:22:57 INFO - 2015-10-30 01:22:57,527 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1151/811
01:22:57 INFO - 2015-10-30 01:22:57,527 DEBUG : BROWSER_OUTPUT: __metrics
01:22:57 INFO - 2015-10-30 01:22:57,669 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:59 INFO - 2015-10-30 01:22:59,161 INFO : Browser initialized.
01:22:59 INFO - 2015-10-30 01:22:59,162 INFO : Running cycle 1/10 for sessionrestore_no_auto_restore test...
01:22:59 INFO - 2015-10-30 01:22:59,162 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp6YRPR7/profile/sessionstore.js
01:22:59 INFO - 2015-10-30 01:22:59,164 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmp6YRPR7/profile http://localhost/startup_test/sessionrestore/index.html
01:23:00 INFO - 2015-10-30 01:23:00,535 DEBUG : BROWSER_OUTPUT: __start_report884__end_report
01:23:00 INFO - 2015-10-30 01:23:00,536 DEBUG : BROWSER_OUTPUT:
01:23:00 INFO - 2015-10-30 01:23:00,536 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193380531__endTimestamp
01:23:00 INFO - 2015-10-30 01:23:00,536 DEBUG : BROWSER_OUTPUT:
01:23:01 INFO - 2015-10-30 01:23:01,449 INFO : Browser exited with error code: 0
01:23:01 INFO - 2015-10-30 01:23:01,451 INFO : Running cycle 2/10 for sessionrestore_no_auto_restore test...
01:23:01 INFO - 2015-10-30 01:23:01,451 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp6YRPR7/profile/sessionstore.js
01:23:01 INFO - 2015-10-30 01:23:01,453 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmp6YRPR7/profile http://localhost/startup_test/sessionrestore/index.html
01:23:02 INFO - 2015-10-30 01:23:02,462 DEBUG : BROWSER_OUTPUT: __start_report606__end_report
01:23:02 INFO - 2015-10-30 01:23:02,463 DEBUG : BROWSER_OUTPUT:
01:23:02 INFO - 2015-10-30 01:23:02,464 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193382460__endTimestamp
01:23:02 INFO - 2015-10-30 01:23:02,464 DEBUG : BROWSER_OUTPUT:
01:23:03 INFO - 2015-10-30 01:23:03,297 INFO : Browser exited with error code: 0
01:23:03 INFO - 2015-10-30 01:23:03,299 INFO : Running cycle 3/10 for sessionrestore_no_auto_restore test...
01:23:03 INFO - 2015-10-30 01:23:03,299 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp6YRPR7/profile/sessionstore.js
01:23:03 INFO - 2015-10-30 01:23:03,301 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmp6YRPR7/profile http://localhost/startup_test/sessionrestore/index.html
01:23:04 INFO - 2015-10-30 01:23:04,371 DEBUG : BROWSER_OUTPUT: __start_report662__end_report
01:23:04 INFO - 2015-10-30 01:23:04,371 DEBUG : BROWSER_OUTPUT:
01:23:04 INFO - 2015-10-30 01:23:04,371 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193384364__endTimestamp
01:23:04 INFO - 2015-10-30 01:23:04,371 DEBUG : BROWSER_OUTPUT:
01:23:05 INFO - 2015-10-30 01:23:05,333 INFO : Browser exited with error code: 0
01:23:05 INFO - 2015-10-30 01:23:05,335 INFO : Running cycle 4/10 for sessionrestore_no_auto_restore test...
01:23:05 INFO - 2015-10-30 01:23:05,335 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp6YRPR7/profile/sessionstore.js
01:23:05 INFO - 2015-10-30 01:23:05,337 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmp6YRPR7/profile http://localhost/startup_test/sessionrestore/index.html
01:23:06 INFO - 2015-10-30 01:23:06,370 DEBUG : BROWSER_OUTPUT: __start_report595__end_report
01:23:06 INFO - 2015-10-30 01:23:06,370 DEBUG : BROWSER_OUTPUT:
01:23:06 INFO - 2015-10-30 01:23:06,371 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193386368__endTimestamp
01:23:06 INFO - 2015-10-30 01:23:06,371 DEBUG : BROWSER_OUTPUT:
01:23:07 INFO - 2015-10-30 01:23:07,185 INFO : Browser exited with error code: 0
01:23:07 INFO - 2015-10-30 01:23:07,187 INFO : Running cycle 5/10 for sessionrestore_no_auto_restore test...
01:23:07 INFO - 2015-10-30 01:23:07,187 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp6YRPR7/profile/sessionstore.js
01:23:07 INFO - 2015-10-30 01:23:07,189 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmp6YRPR7/profile http://localhost/startup_test/sessionrestore/index.html
01:23:08 INFO - 2015-10-30 01:23:08,278 DEBUG : BROWSER_OUTPUT: __start_report644__end_report
01:23:08 INFO - 2015-10-30 01:23:08,278 DEBUG : BROWSER_OUTPUT:
01:23:08 INFO - 2015-10-30 01:23:08,278 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193388276__endTimestamp
01:23:08 INFO - 2015-10-30 01:23:08,278 DEBUG : BROWSER_OUTPUT:
01:23:09 INFO - 2015-10-30 01:23:09,225 INFO : Browser exited with error code: 0
01:23:09 INFO - 2015-10-30 01:23:09,227 INFO : Running cycle 6/10 for sessionrestore_no_auto_restore test...
01:23:09 INFO - 2015-10-30 01:23:09,227 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp6YRPR7/profile/sessionstore.js
01:23:09 INFO - 2015-10-30 01:23:09,229 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmp6YRPR7/profile http://localhost/startup_test/sessionrestore/index.html
01:23:10 INFO - 2015-10-30 01:23:10,241 DEBUG : BROWSER_OUTPUT: __start_report606__end_report
01:23:10 INFO - 2015-10-30 01:23:10,241 DEBUG : BROWSER_OUTPUT:
01:23:10 INFO - 2015-10-30 01:23:10,241 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193390238__endTimestamp
01:23:10 INFO - 2015-10-30 01:23:10,241 DEBUG : BROWSER_OUTPUT:
01:23:11 INFO - 2015-10-30 01:23:11,169 INFO : Browser exited with error code: 0
01:23:11 INFO - 2015-10-30 01:23:11,171 INFO : Running cycle 7/10 for sessionrestore_no_auto_restore test...
01:23:11 INFO - 2015-10-30 01:23:11,171 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp6YRPR7/profile/sessionstore.js
01:23:11 INFO - 2015-10-30 01:23:11,173 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmp6YRPR7/profile http://localhost/startup_test/sessionrestore/index.html
01:23:12 INFO - 2015-10-30 01:23:12,201 DEBUG : BROWSER_OUTPUT: __start_report614__end_report
01:23:12 INFO - 2015-10-30 01:23:12,202 DEBUG : BROWSER_OUTPUT:
01:23:12 INFO - 2015-10-30 01:23:12,202 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193392195__endTimestamp
01:23:12 INFO - 2015-10-30 01:23:12,202 DEBUG : BROWSER_OUTPUT:
01:23:13 INFO - 2015-10-30 01:23:13,169 INFO : Browser exited with error code: 0
01:23:13 INFO - 2015-10-30 01:23:13,171 INFO : Running cycle 8/10 for sessionrestore_no_auto_restore test...
01:23:13 INFO - 2015-10-30 01:23:13,171 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp6YRPR7/profile/sessionstore.js
01:23:13 INFO - 2015-10-30 01:23:13,173 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmp6YRPR7/profile http://localhost/startup_test/sessionrestore/index.html
01:23:14 INFO - 2015-10-30 01:23:14,190 DEBUG : BROWSER_OUTPUT: __start_report587__end_report
01:23:14 INFO - 2015-10-30 01:23:14,190 DEBUG : BROWSER_OUTPUT:
01:23:14 INFO - 2015-10-30 01:23:14,190 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193394188__endTimestamp
01:23:14 INFO - 2015-10-30 01:23:14,190 DEBUG : BROWSER_OUTPUT:
01:23:15 INFO - 2015-10-30 01:23:15,121 INFO : Browser exited with error code: 0
01:23:15 INFO - 2015-10-30 01:23:15,123 INFO : Running cycle 9/10 for sessionrestore_no_auto_restore test...
01:23:15 INFO - 2015-10-30 01:23:15,123 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp6YRPR7/profile/sessionstore.js
01:23:15 INFO - 2015-10-30 01:23:15,125 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmp6YRPR7/profile http://localhost/startup_test/sessionrestore/index.html
01:23:16 INFO - 2015-10-30 01:23:16,134 DEBUG : BROWSER_OUTPUT: __start_report611__end_report
01:23:16 INFO - 2015-10-30 01:23:16,134 DEBUG : BROWSER_OUTPUT:
01:23:16 INFO - 2015-10-30 01:23:16,134 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193396131__endTimestamp
01:23:16 INFO - 2015-10-30 01:23:16,134 DEBUG : BROWSER_OUTPUT:
01:23:17 INFO - 2015-10-30 01:23:17,121 INFO : Browser exited with error code: 0
01:23:17 INFO - 2015-10-30 01:23:17,123 INFO : Running cycle 10/10 for sessionrestore_no_auto_restore test...
01:23:17 INFO - 2015-10-30 01:23:17,123 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp6YRPR7/profile/sessionstore.js
01:23:17 INFO - 2015-10-30 01:23:17,125 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmp6YRPR7/profile http://localhost/startup_test/sessionrestore/index.html
01:23:18 INFO - 2015-10-30 01:23:18,173 DEBUG : BROWSER_OUTPUT: __start_report598__end_report
01:23:18 INFO - 2015-10-30 01:23:18,174 DEBUG : BROWSER_OUTPUT:
01:23:18 INFO - 2015-10-30 01:23:18,174 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193398167__endTimestamp
01:23:18 INFO - 2015-10-30 01:23:18,174 DEBUG : BROWSER_OUTPUT:
01:23:19 INFO - 2015-10-30 01:23:19,113 INFO : Browser exited with error code: 0
01:23:19 INFO - 2015-10-30 01:23:19,131 INFO : Completed test sessionrestore_no_auto_restore (00:00:25)
01:23:19 INFO - 2015-10-30 01:23:19,131 INFO : Completed test suite (00:03:55)
01:23:19 INFO - 2015-10-30 01:23:19,131 DEBUG : Working with test: a11yr
01:23:19 INFO - 2015-10-30 01:23:19,131 DEBUG : Generating results file: a11yr
01:23:19 INFO - 2015-10-30 01:23:19,131 DEBUG : Working with test: ts_paint
01:23:19 INFO - 2015-10-30 01:23:19,131 DEBUG : Generating results file: ts_paint
01:23:19 INFO - 2015-10-30 01:23:19,131 DEBUG : Working with test: tpaint
01:23:19 INFO - 2015-10-30 01:23:19,131 DEBUG : Generating results file: tpaint
01:23:19 INFO - 2015-10-30 01:23:19,132 DEBUG : Working with test: sessionrestore
01:23:19 INFO - 2015-10-30 01:23:19,132 DEBUG : Generating results file: sessionrestore
01:23:19 INFO - 2015-10-30 01:23:19,132 DEBUG : Working with test: sessionrestore_no_auto_restore
01:23:19 INFO - 2015-10-30 01:23:19,132 DEBUG : Generating results file: sessionrestore_no_auto_restore
01:23:19 INFO - 2015-10-30 01:23:19,132 INFO : Posting result 0 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
01:23:19 INFO - 2015-10-30 01:23:19,180 DEBUG : process_Request line: a11yr_paint graph.html#tests=[[223,52,35]]
01:23:19 INFO - 2015-10-30 01:23:19,181 DEBUG : process_Request line: a11yr_paint 425.65 graph.html#tests=[[223,52,35]]
01:23:19 INFO - 2015-10-30 01:23:19,181 INFO : Posting result 1 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
01:23:19 INFO - 2015-10-30 01:23:19,256 DEBUG : process_Request line: ts_paint graph.html#tests=[[83,52,35]]
01:23:19 INFO - 2015-10-30 01:23:19,256 DEBUG : process_Request line: ts_paint 944.92 graph.html#tests=[[83,52,35]]
01:23:19 INFO - 2015-10-30 01:23:19,256 INFO : Posting result 2 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
01:23:19 INFO - 2015-10-30 01:23:19,293 DEBUG : process_Request line: tpaint graph.html#tests=[[82,52,35]]
01:23:19 INFO - 2015-10-30 01:23:19,293 DEBUG : process_Request line: tpaint 175.65 graph.html#tests=[[82,52,35]]
01:23:19 INFO - 2015-10-30 01:23:19,294 INFO : Posting result 3 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
01:23:19 INFO - 2015-10-30 01:23:19,343 DEBUG : process_Request line: sessionrestore graph.html#tests=[[313,52,35]]
01:23:19 INFO - 2015-10-30 01:23:19,343 DEBUG : process_Request line: sessionrestore 1497.35 graph.html#tests=[[313,52,35]]
01:23:19 INFO - 2015-10-30 01:23:19,343 INFO : Posting result 4 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
01:23:19 INFO - 2015-10-30 01:23:19,393 DEBUG : process_Request line: sessionrestore_no_auto_restore graph.html#tests=[[315,52,35]]
01:23:19 INFO - 2015-10-30 01:23:19,393 DEBUG : process_Request line: sessionrestore_no_auto_restore 636.10 graph.html#tests=[[315,52,35]]
01:23:19 INFO - 2015-10-30 01:23:19,395 INFO : TALOSDATA: [{"talos_counters": {}, "results": {"dhtml.html": [864.0, 909.0, 852.0, 918.0, 914.0, 921.0, 923.0, 923.0, 855.0, 924.0, 921.0, 926.0, 958.0, 931.0, 923.0, 861.0, 938.0, 992.0, 928.0, 1000.0, 929.0, 922.0, 921.0, 993.0, 923.0], "tablemutation.html": [203.0, 196.0, 197.0, 196.0, 195.0, 194.0, 195.0, 195.0, 203.0, 199.0, 197.0, 196.0, 198.0, 196.0, 195.0, 198.0, 197.0, 196.0, 196.0, 196.0, 198.0, 197.0, 197.0, 196.0, 196.0]}, "summary": {"suite": 425.64739539812047, "subtests": {"dhtml.html": {"std": 35.87127351919483, "min": 852.0, "max": 1000.0, "median": 923.0, "filtered": 923.0, "mean": 925.2083333333334}, "tablemutation.html": {"std": 1.7514874630819752, "min": 194.0, "max": 203.0, "median": 196.0, "filtered": 196.0, "mean": 196.625}}}, "test_machine": {"platform": "x86_64", "osversion": "Ubuntu 12.04", "os": "linux", "name": "talos-linux64-ix-041"}, "testrun": {"date": 1446193163, "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": [1408.0, 907.0, 929.0, 906.0, 924.0, 948.0, 900.0, 901.0, 888.0, 959.0, 945.0, 900.0, 944.0, 924.0, 980.0, 914.0, 947.0, 914.0, 932.0, 924.0]}, "summary": {"suite": 924.0, "subtests": {"ts_paint": {"std": 23.100047367173318, "min": 888.0, "max": 980.0, "median": 924.0, "filtered": 924.0, "mean": 925.578947368421}}}, "test_machine": {"platform": "x86_64", "osversion": "Ubuntu 12.04", "os": "linux", "name": "talos-linux64-ix-041"}, "testrun": {"date": 1446193163, "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": [154.4649999999997, 154.54499999999985, 155.5650000000005, 155.71999999999753, 156.51000000000113, 159.875, 161.10999999999876, 161.95000000000073, 167.01999999999998, 172.6800000000003, 173.51499999999942, 174.47000000000116, 175.65499999999884, 176.26999999999862, 179.33500000000095, 183.79499999999825, 187.35499999999956, 190.1449999999968, 204.45000000000073, 249.59000000000015]}, "summary": {"suite": 175.65499999999884, "subtests": {"tpaint": {"std": 21.614525815345182, "min": 159.875, "max": 249.59000000000015, "median": 175.65499999999884, "filtered": 175.65499999999884, "mean": 181.14766666666628}}}, "test_machine": {"platform": "x86_64", "osversion": "Ubuntu 12.04", "os": "linux", "name": "talos-linux64-ix-041"}, "testrun": {"date": 1446193163, "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": [1734.0, 1465.0, 1446.0, 1491.0, 1469.0, 1469.0, 1494.0, 1490.0, 1453.0, 1482.0]}, "summary": {"suite": 1469.0, "subtests": {"sessionrestore": {"std": 16.191752206174996, "min": 1446.0, "max": 1494.0, "median": 1469.0, "filtered": 1469.0, "mean": 1473.2222222222222}}}, "test_machine": {"platform": "x86_64", "osversion": "Ubuntu 12.04", "os": "linux", "name": "talos-linux64-ix-041"}, "testrun": {"date": 1446193163, "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": [884.0, 606.0, 662.0, 595.0, 644.0, 606.0, 614.0, 587.0, 611.0, 598.0]}, "summary": {"suite": 606.0, "subtests": {"sessionrestore_no_auto_restore": {"std": 22.818121453499778, "min": 587.0, "max": 662.0, "median": 606.0, "filtered": 606.0, "mean": 613.6666666666666}}}, "test_machine": {"platform": "x86_64", "osversion": "Ubuntu 12.04", "os": "linux", "name": "talos-linux64-ix-041"}, "testrun": {"date": 1446193163, "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:19 INFO - RETURN: a11yr_paint: 425.65
01:23:19 INFO - RETURN: ts_paint: 944.92
01:23:19 INFO - RETURN: tpaint: 175.65
01:23:19 INFO - RETURN: sessionrestore: 1497.35
01:23:19 INFO - RETURN: sessionrestore_no_auto_restore: 636.10
01:23:19 INFO - TinderboxPrint: TalosResult: {"graphserver": {"sessionrestore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[313,52,35]]", "result": "1497.35"}, "a11yr_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[223,52,35]]", "result": "425.65"}, "tpaint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[82,52,35]]", "result": "175.65"}, "ts_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[83,52,35]]", "result": "944.92"}, "sessionrestore_no_auto_restore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[315,52,35]]", "result": "636.10"}}}
01:23:19 INFO - Return code: 0
01:23:19 INFO - # TBPL SUCCESS #
01:23:19 INFO - Running post-action listener: _resource_record_post_action
01:23:19 INFO - Running post-run listener: _resource_record_post_run
01:23:20 INFO - Total resource usage - Wall time: 250s; CPU: 13.0%; Read bytes: 4665344; Write bytes: 359305216; Read time: 1764; Write time: 345632
01:23:20 INFO - install - Wall time: 14s; CPU: 13.0%; Read bytes: 0; Write bytes: 462848; Read time: 0; Write time: 52
01:23:20 INFO - run-tests - Wall time: 236s; CPU: 13.0%; Read bytes: 2904064; Write bytes: 311754752; Read time: 1344; Write time: 305568
01:23:20 INFO - Running post-run listener: _upload_blobber_files
01:23:20 INFO - Blob upload gear active.
01:23:20 INFO - There are no files to upload in the directory. Skipping the blob upload mechanism ...
01:23:20 INFO - Copying logs to upload dir...
01:23:20 INFO - mkdir: /builds/slave/test-pgo/build/upload/logs
program finished with exit code 0
elapsedTime=307.807514
========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 5 mins, 7 secs) (at 2015-10-30 01:23:20.444779) =========
========= Started set props: build_url (results: 0, elapsed: 0 secs) (at 2015-10-30 01:23:20.448425) =========
bash -c 'for file in `ls -1`; do cat $file; done'
in dir /builds/slave/test-pgo/properties (timeout 1200 secs)
watching logfiles {}
argv: ['bash', '-c', 'for file in `ls -1`; do cat $file; done']
environment:
DISPLAY=:0
HOME=/home/cltbld
LANG=en_US.UTF-8
LANGUAGE=en_US:en
LOGNAME=cltbld
MAIL=/var/mail/cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript
NO_EM_RESTART=1
PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
PWD=/builds/slave/test-pgo/properties
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
build_url:https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2
program finished with exit code 0
elapsedTime=0.009877
build_url: 'https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2'
========= Finished set props: build_url (results: 0, elapsed: 0 secs) (at 2015-10-30 01:23:20.501733) =========
========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:23:20.502124) =========
rm -f oauth.txt
in dir /builds/slave/test-pgo/. (timeout 1200 secs)
watching logfiles {}
argv: ['rm', '-f', 'oauth.txt']
environment:
DISPLAY=:0
HOME=/home/cltbld
LANG=en_US.UTF-8
LANGUAGE=en_US:en
LOGNAME=cltbld
MAIL=/var/mail/cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript
NO_EM_RESTART=1
PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
PWD=/builds/slave/test-pgo
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
program finished with exit code 0
elapsedTime=0.004520
========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:23:20.551769) =========
========= Started reboot slave lost (results: 0, elapsed: 4 secs) (at 2015-10-30 01:23:20.552092) =========
========= Finished reboot slave lost (results: 0, elapsed: 4 secs) (at 2015-10-30 01:23:24.820086) =========