builder: mozilla-inbound_ubuntu64_hw_test-other
slave: talos-linux64-ix-048
starttime: 1447352668.71
results: success (0)
buildid: 20151112100440
builduid: fc42b1225b304fbc87b60387fbfad0da
revision: 756632e20aa46ce0b2feebdf6f04e6dacdc09811
========= Started set props: master (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:28.706713) =========
master: http://buildbot-master104.bb.releng.scl3.mozilla.com:8201/
========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:28.707153) =========
========= Started set props: basedir (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:28.707459) =========
bash -c pwd
in dir /builds/slave/test/. (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
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
/builds/slave/test
program finished with exit code 0
elapsedTime=0.006572
basedir: '/builds/slave/test'
========= master_lag: 0.02 =========
========= Finished set props: basedir (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:28.736342) =========
========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:28.736662) =========
========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:28.777377) =========
========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:28.777648) =========
rm -rf properties
in dir /builds/slave/test/. (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
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
program finished with exit code 0
elapsedTime=0.004707
========= master_lag: 0.07 =========
========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:28.847471) =========
========= Started set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:28.847749) =========
script_repo_url: https://hg.mozilla.org/build/mozharness
========= Finished set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:28.848081) =========
========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:28.848608) =========
bash -c 'wget -Oarchiver_client.py --no-check-certificate --tries=10 --waitretry=3 https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py'
in dir /builds/slave/test/. (timeout 1200 secs)
watching logfiles {}
argv: ['bash', '-c', 'wget -Oarchiver_client.py --no-check-certificate --tries=10 --waitretry=3 https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py']
environment:
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
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
--2015-11-12 10:24:30-- 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% 84.0M=0s
2015-11-12 10:24:30 (84.0 MB/s) - `archiver_client.py' saved [12141/12141]
program finished with exit code 0
elapsedTime=0.119738
========= master_lag: 0.34 =========
========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:29.308851) =========
========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:29.312372) =========
rm -rf scripts
in dir /builds/slave/test/. (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
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
program finished with exit code 0
elapsedTime=0.020370
========= master_lag: 0.05 =========
========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:29.383721) =========
========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:29.384082) =========
bash -c 'python archiver_client.py mozharness --repo integration/mozilla-inbound --rev 756632e20aa46ce0b2feebdf6f04e6dacdc09811 --destination scripts --debug'
in dir /builds/slave/test/. (timeout 1200 secs)
watching logfiles {}
argv: ['bash', '-c', u'python archiver_client.py mozharness --repo integration/mozilla-inbound --rev 756632e20aa46ce0b2feebdf6f04e6dacdc09811 --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
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
2015-11-12 10:24:30,694 truncating revision to first 12 chars
2015-11-12 10:24:30,694 Setting DEBUG logging.
2015-11-12 10:24:30,694 attempt 1/10
2015-11-12 10:24:30,694 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/integration/mozilla-inbound/756632e20aa4?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness
2015-11-12 10:24:31,050 unpacking tar archive at: mozilla-inbound-756632e20aa4/testing/mozharness/
program finished with exit code 0
elapsedTime=0.652951
========= master_lag: 0.03 =========
========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:30.069903) =========
========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:30.070189) =========
========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:30.078069) =========
========= Started tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:30.078335) =========
TinderboxPrint: script_revlink: https://hg.mozilla.org/build/mozharness/rev/production
========= Finished tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:30.078686) =========
========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 5 mins, 37 secs) (at 2015-11-12 10:24:30.078964) =========
/tools/buildbot/bin/python scripts/scripts/talos_script.py --suite other --add-option --webServer,localhost --branch-name Mozilla-Inbound-Non-PGO --system-bits 64 --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Mozilla-Inbound-Non-PGO
in dir /builds/slave/test/. (timeout 3600 secs) (maxTime 7200 secs)
watching logfiles {}
argv: ['/tools/buildbot/bin/python', 'scripts/scripts/talos_script.py', '--suite', 'other', '--add-option', '--webServer,localhost', '--branch-name', 'Mozilla-Inbound-Non-PGO', '--system-bits', '64', '--cfg', 'talos/linux_config.py', '--download-symbols', 'ondemand', '--use-talos-json', '--blob-upload-branch', 'Mozilla-Inbound-Non-PGO']
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/buildprops.json
PWD=/builds/slave/test
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
10:24:31 INFO - MultiFileLogger online at 20151112 10:24:31 in /builds/slave/test
10:24:31 INFO - Run as scripts/scripts/talos_script.py --suite other --add-option --webServer,localhost --branch-name Mozilla-Inbound-Non-PGO --system-bits 64 --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Mozilla-Inbound-Non-PGO
10:24:31 INFO - Dumping config to /builds/slave/test/logs/localconfig.json.
10:24:31 INFO - {'append_to_log': False,
10:24:31 INFO - 'base_work_dir': '/builds/slave/test',
10:24:31 INFO - 'blob_upload_branch': 'Mozilla-Inbound-Non-PGO',
10:24:31 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt',
10:24:31 INFO - 'branch': 'Mozilla-Inbound-Non-PGO',
10:24:31 INFO - 'buildbot_json_path': 'buildprops.json',
10:24:31 INFO - 'config_files': ('talos/linux_config.py',),
10:24:31 INFO - 'default_actions': ('clobber',
10:24:31 INFO - 'read-buildbot-config',
10:24:31 INFO - 'download-and-extract',
10:24:31 INFO - 'populate-webroot',
10:24:31 INFO - 'create-virtualenv',
10:24:31 INFO - 'install',
10:24:31 INFO - 'run-tests'),
10:24:31 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',),
10:24:31 INFO - 'download_minidump_stackwalk': True,
10:24:31 INFO - 'download_symbols': 'ondemand',
10:24:31 INFO - 'exes': {'python': '/tools/buildbot/bin/python',
10:24:31 INFO - 'tooltool.py': '/tools/tooltool.py',
10:24:31 INFO - 'virtualenv': ('/tools/buildbot/bin/python',
10:24:31 INFO - '/tools/misc-python/virtualenv.py')},
10:24:31 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub',
10:24:31 INFO - 'http://pypi.pub.build.mozilla.org/pub'),
10:24:31 INFO - 'installer_path': 'installer.exe',
10:24:31 INFO - 'log_level': 'info',
10:24:31 INFO - 'log_name': 'talos',
10:24:31 INFO - 'log_to_console': True,
10:24:31 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk',
10:24:31 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest',
10:24:31 INFO - 'opt_config_files': (),
10:24:31 INFO - 'pip_index': False,
10:24:31 INFO - 'sps_profile': False,
10:24:31 INFO - 'sps_profile_interval': 0,
10:24:31 INFO - 'suite': 'other',
10:24:31 INFO - 'system_bits': '64',
10:24:31 INFO - 'talos_extra_options': ('--webServer', 'localhost'),
10:24:31 INFO - 'title': 'talos-linux64-ix-048',
10:24:31 INFO - 'tooltool_cache': '/builds/tooltool_cache',
10:24:31 INFO - 'use_talos_json': True,
10:24:31 INFO - 'virtualenv_path': '/builds/slave/test/build/venv',
10:24:31 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None},
10:24:31 INFO - 'work_dir': 'build'}
10:24:31 INFO - #####
10:24:31 INFO - ##### Running clobber step.
10:24:31 INFO - #####
10:24:31 INFO - Running pre-action listener: _resource_record_pre_action
10:24:31 INFO - Running main action method: clobber
10:24:31 INFO - rmtree: /builds/slave/test/build
10:24:31 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1
10:24:31 INFO - Running post-action listener: _resource_record_post_action
10:24:31 INFO - #####
10:24:31 INFO - ##### Running read-buildbot-config step.
10:24:31 INFO - #####
10:24:31 INFO - Running pre-action listener: _resource_record_pre_action
10:24:31 INFO - Running main action method: read_buildbot_config
10:24:31 INFO - Using buildbot properties:
10:24:31 INFO - {
10:24:31 INFO - "properties": {
10:24:31 INFO - "buildnumber": 707,
10:24:31 INFO - "product": "firefox",
10:24:31 INFO - "script_repo_revision": "production",
10:24:31 INFO - "builddir": "mozilla-inbound_ubuntu64_hw_test-other",
10:24:31 INFO - "repository": "",
10:24:31 INFO - "buildername": "Ubuntu HW 12.04 x64 mozilla-inbound talos other",
10:24:31 INFO - "buildid": "20151112100440",
10:24:31 INFO - "slavename": "talos-linux64-ix-048",
10:24:31 INFO - "pgo_build": "False",
10:24:31 INFO - "basedir": "/builds/slave/test",
10:24:31 INFO - "project": "",
10:24:31 INFO - "platform": "ubuntu64_hw",
10:24:31 INFO - "master": "http://buildbot-master104.bb.releng.scl3.mozilla.com:8201/",
10:24:31 INFO - "slavebuilddir": "test",
10:24:31 INFO - "scheduler": "tests-mozilla-inbound-linux64-talos",
10:24:31 INFO - "branch": "mozilla-inbound",
10:24:31 INFO - "repo_path": "integration/mozilla-inbound",
10:24:31 INFO - "stage_platform": "linux64",
10:24:31 INFO - "builduid": "fc42b1225b304fbc87b60387fbfad0da",
10:24:31 INFO - "revision": "756632e20aa46ce0b2feebdf6f04e6dacdc09811"
10:24:31 INFO - },
10:24:31 INFO - "sourcestamp": {
10:24:31 INFO - "repository": "",
10:24:31 INFO - "hasPatch": false,
10:24:31 INFO - "project": "",
10:24:31 INFO - "branch": "mozilla-inbound-linux64-talos",
10:24:31 INFO - "changes": [
10:24:31 INFO - {
10:24:31 INFO - "category": null,
10:24:31 INFO - "files": [
10:24:31 INFO - {
10:24:31 INFO - "url": null,
10:24:31 INFO - "name": "https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2"
10:24:31 INFO - }
10:24:31 INFO - ],
10:24:31 INFO - "repository": "",
10:24:31 INFO - "rev": "756632e20aa46ce0b2feebdf6f04e6dacdc09811",
10:24:31 INFO - "who": "nfroyd@mozilla.com",
10:24:31 INFO - "when": 1447352650,
10:24:31 INFO - "number": 6654258,
10:24:31 INFO - "comments": "Bug 1221547 - part 2 - copy less data for file transfers over bluetooth; r=btian\n\nWe have a number of places where we create a Bluetooth request with\nallocated memory, then copy that memory into the raw data to be sent\nover the socket. We can do better by transferring ownership to the\nsocket data, rather than copying.",
10:24:31 INFO - "project": "",
10:24:31 INFO - "at": "Thu 12 Nov 2015 10:24:10",
10:24:31 INFO - "branch": "mozilla-inbound-linux64-talos",
10:24:31 INFO - "revlink": "",
10:24:31 INFO - "properties": [
10:24:31 INFO - [
10:24:31 INFO - "buildid",
10:24:31 INFO - "20151112100440",
10:24:31 INFO - "Change"
10:24:31 INFO - ],
10:24:31 INFO - [
10:24:31 INFO - "builduid",
10:24:31 INFO - "fc42b1225b304fbc87b60387fbfad0da",
10:24:31 INFO - "Change"
10:24:31 INFO - ],
10:24:31 INFO - [
10:24:31 INFO - "pgo_build",
10:24:31 INFO - "False",
10:24:31 INFO - "Change"
10:24:31 INFO - ]
10:24:31 INFO - ],
10:24:31 INFO - "revision": "756632e20aa46ce0b2feebdf6f04e6dacdc09811"
10:24:31 INFO - }
10:24:31 INFO - ],
10:24:31 INFO - "revision": "756632e20aa46ce0b2feebdf6f04e6dacdc09811"
10:24:31 INFO - }
10:24:31 INFO - }
10:24:31 INFO - Found installer url https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2.
10:24:31 INFO - Running post-action listener: _resource_record_post_action
10:24:31 INFO - #####
10:24:31 INFO - ##### Running download-and-extract step.
10:24:31 INFO - #####
10:24:31 INFO - Running pre-action listener: _resource_record_pre_action
10:24:31 INFO - Running main action method: download_and_extract
10:24:31 INFO - mkdir: /builds/slave/test/build/tests
10:24:31 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:24:31 INFO - https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/test_packages.json matches https://queue.taskcluster.net
10:24:31 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/test_packages.json
10:24:31 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/test_packages.json
10:24:31 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/test_packages.json to /builds/slave/test/build/test_packages.json
10:24:31 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/test_packages.json', 'file_name': '/builds/slave/test/build/test_packages.json'}, attempt #1
10:24:36 INFO - Downloaded 1302 bytes.
10:24:36 INFO - Reading from file /builds/slave/test/build/test_packages.json
10:24:36 INFO - Using the following test package requirements:
10:24:36 INFO - {u'common': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'],
10:24:36 INFO - u'cppunittest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
10:24:36 INFO - u'firefox-45.0a1.en-US.linux-x86_64.cppunittest.tests.zip'],
10:24:36 INFO - u'jittest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
10:24:36 INFO - u'jsshell-linux-x86_64.zip'],
10:24:36 INFO - u'mochitest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
10:24:36 INFO - u'firefox-45.0a1.en-US.linux-x86_64.mochitest.tests.zip'],
10:24:36 INFO - u'mozbase': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'],
10:24:36 INFO - u'reftest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
10:24:36 INFO - u'firefox-45.0a1.en-US.linux-x86_64.reftest.tests.zip'],
10:24:36 INFO - u'talos': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
10:24:36 INFO - u'firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip'],
10:24:36 INFO - u'web-platform': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
10:24:36 INFO - u'firefox-45.0a1.en-US.linux-x86_64.web-platform.tests.zip'],
10:24:36 INFO - u'webapprt': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'],
10:24:36 INFO - u'xpcshell': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
10:24:36 INFO - u'firefox-45.0a1.en-US.linux-x86_64.xpcshell.tests.zip']}
10:24:36 INFO - Downloading packages: [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'] for test suite category: common
10:24:36 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:24:36 INFO - https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip matches https://queue.taskcluster.net
10:24:36 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
10:24:36 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
10:24:36 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip to /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
10:24:36 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 'file_name': u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'}, attempt #1
10:24:37 INFO - Downloaded 21256990 bytes.
10:24:37 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'] in /builds/slave/test/build/tests
10:24:37 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
10:24:37 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'] with output_timeout 1760
10:24:38 INFO - Return code: 0
10:24:38 INFO - Downloading packages: [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', u'firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip'] for test suite category: talos
10:24: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')]}
10:24:38 INFO - https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip matches https://queue.taskcluster.net
10:24:38 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
10:24:38 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
10:24:38 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip to /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
10:24:38 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 'file_name': u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'}, attempt #1
10:24:40 INFO - Downloaded 21256990 bytes.
10:24:40 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'] in /builds/slave/test/build/tests
10:24:40 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
10:24:40 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'] with output_timeout 1760
10:24:41 INFO - Return code: 0
10:24:41 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')]}
10:24:41 INFO - https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip matches https://queue.taskcluster.net
10:24:41 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip
10:24:41 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip
10:24:41 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip to /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip
10:24:41 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip', 'file_name': u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip'}, attempt #1
10:24:42 INFO - Downloaded 11131693 bytes.
10:24:42 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip'] in /builds/slave/test/build/tests
10:24:42 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip
10:24:42 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip'] with output_timeout 1760
10:24:42 INFO - Return code: 0
10:24: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')]}
10:24:42 INFO - https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 matches https://queue.taskcluster.net
10:24:42 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2
10:24:42 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2
10:24:42 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 to /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2
10:24:42 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2', 'file_name': '/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2'}, attempt #1
10:24:43 INFO - Downloaded 55657694 bytes.
10:24:43 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2
10:24:43 INFO - mkdir: /builds/slave/test/properties
10:24:43 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url
10:24:43 INFO - Writing to file /builds/slave/test/properties/build_url
10:24:43 INFO - Contents:
10:24:43 INFO - build_url:https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2
10:24:43 INFO - Running post-action listener: _resource_record_post_action
10:24:43 INFO - Running post-action listener: set_extra_try_arguments
10:24:43 INFO - #####
10:24:43 INFO - ##### Running populate-webroot step.
10:24:43 INFO - #####
10:24:43 INFO - Running pre-action listener: _resource_record_pre_action
10:24:43 INFO - Running main action method: populate_webroot
10:24:43 INFO - {'extra_options': {'android': ['--apkPath=%(apk_path)s']},
10:24:43 INFO - 'mobile-suites': {'remote-tp4m_nochrome': {'tests': ['tp4m']},
10:24:43 INFO - 'remote-trobocheck2': {'talos_options': ['--fennecIDs',
10:24:43 INFO - '../fennec_ids.txt'],
10:24:43 INFO - 'tests': ['tcheck2']},
10:24:43 INFO - 'remote-tsvgx': {'talos_options': ['--noChrome',
10:24:43 INFO - '--tppagecycles',
10:24:43 INFO - '7'],
10:24:43 INFO - 'tests': ['tsvgm']}},
10:24:43 INFO - 'suites': {'chromez': {'tests': ['tresize', 'tcanvasmark']},
10:24:43 INFO - 'chromez-e10s': {'talos_options': ['--e10s'],
10:24:43 INFO - 'tests': ['tresize', 'tcanvasmark']},
10:24:43 INFO - 'dromaeojs': {'tests': ['dromaeo_css', 'kraken', 'v8_7']},
10:24:43 INFO - 'dromaeojs-e10s': {'talos_options': ['--e10s'],
10:24:43 INFO - 'tests': ['dromaeo_css', 'kraken', 'v8_7']},
10:24:43 INFO - 'g1': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
10:24:43 INFO - 'tests': ['tp5o_scroll', 'glterrain']},
10:24:43 INFO - 'g1-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
10:24:43 INFO - 'talos_options': ['--e10s'],
10:24:43 INFO - 'tests': ['tp5o_scroll', 'glterrain']},
10:24:43 INFO - 'g2': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
10:24:43 INFO - 'tests': ['damp', 'tps']},
10:24:43 INFO - 'g2-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
10:24:43 INFO - 'talos_options': ['--e10s'],
10:24:43 INFO - 'tests': ['damp', 'tps']},
10:24:43 INFO - 'g3': {'tests': ['dromaeo_dom']},
10:24:43 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']},
10:24:43 INFO - 'other': {'tests': ['a11yr',
10:24:43 INFO - 'ts_paint',
10:24:43 INFO - 'tpaint',
10:24:43 INFO - 'sessionrestore',
10:24:43 INFO - 'sessionrestore_no_auto_restore']},
10:24:43 INFO - 'other-e10s': {'talos_options': ['--e10s'],
10:24:43 INFO - 'tests': ['a11yr',
10:24:43 INFO - 'ts_paint',
10:24:43 INFO - 'tpaint',
10:24:43 INFO - 'sessionrestore',
10:24:43 INFO - 'sessionrestore_no_auto_restore']},
10:24:43 INFO - 'other-e10s_l64': {'talos_options': ['--e10s'],
10:24:43 INFO - 'tests': ['a11yr',
10:24:43 INFO - 'ts_paint',
10:24:43 INFO - 'tpaint',
10:24:43 INFO - 'sessionrestore',
10:24:43 INFO - 'sessionrestore_no_auto_restore']},
10:24:43 INFO - 'other-e10s_nol64': {'talos_options': ['--e10s'],
10:24:43 INFO - 'tests': ['a11yr',
10:24:43 INFO - 'ts_paint',
10:24:43 INFO - 'tpaint',
10:24:43 INFO - 'sessionrestore',
10:24:43 INFO - 'sessionrestore_no_auto_restore']},
10:24:43 INFO - 'other_l64': {'tests': ['a11yr',
10:24:43 INFO - 'ts_paint',
10:24:43 INFO - 'tpaint',
10:24:43 INFO - 'sessionrestore',
10:24:43 INFO - 'sessionrestore_no_auto_restore']},
10:24:43 INFO - 'other_nol64': {'tests': ['a11yr',
10:24:43 INFO - 'ts_paint',
10:24:43 INFO - 'tpaint',
10:24:43 INFO - 'sessionrestore',
10:24:43 INFO - 'sessionrestore_no_auto_restore']},
10:24:43 INFO - 'svgr': {'tests': ['tsvgx',
10:24:43 INFO - 'tsvgr_opacity',
10:24:43 INFO - 'tart',
10:24:43 INFO - 'tscrollx',
10:24:43 INFO - 'cart']},
10:24:43 INFO - 'svgr-e10s': {'talos_options': ['--e10s'],
10:24:43 INFO - 'tests': ['tsvgx',
10:24:43 INFO - 'tsvgr_opacity',
10:24:43 INFO - 'tart',
10:24:43 INFO - 'tscrollx',
10:24:43 INFO - 'cart']},
10:24:43 INFO - 'tp5o': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
10:24:43 INFO - 'tests': ['tp5o']},
10:24:43 INFO - 'tp5o-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
10:24:43 INFO - 'talos_options': ['--e10s'],
10:24:43 INFO - 'tests': ['tp5o']},
10:24:43 INFO - 'xperf': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
10:24:43 INFO - 'talos_options': ['--xperf_path',
10:24:43 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'],
10:24:43 INFO - 'tests': ['tp5n']},
10:24:43 INFO - 'xperf-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
10:24:43 INFO - 'talos_options': ['--e10s',
10:24:43 INFO - '--xperf_path',
10:24:43 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'],
10:24:43 INFO - 'tests': ['tp5n']}},
10:24:43 INFO - 'talos.zip': {'path': '',
10:24:43 INFO - 'url': 'http://talos-bundles.pvt.build.mozilla.org/zips/talos.a6052c33d420.zip'}}
10:24:43 INFO - Running post-action listener: _resource_record_post_action
10:24:43 INFO - #####
10:24:43 INFO - ##### Running create-virtualenv step.
10:24:43 INFO - #####
10:24:43 INFO - Running pre-action listener: _resource_record_pre_action
10:24:43 INFO - Running main action method: create_virtualenv
10:24:43 INFO - Creating virtualenv /builds/slave/test/build/venv
10:24:43 INFO - Running command: ['/tools/buildbot/bin/python', '/tools/misc-python/virtualenv.py', '--no-site-packages', '--distribute', '/builds/slave/test/build/venv'] in /builds/slave/test/build
10:24:43 INFO - Copy/paste: /tools/buildbot/bin/python /tools/misc-python/virtualenv.py --no-site-packages --distribute /builds/slave/test/build/venv
10:24:43 INFO - The --no-site-packages flag is deprecated; it is now the default behavior.
10:24:43 INFO - Using real prefix '/usr'
10:24:43 INFO - New python executable in /builds/slave/test/build/venv/bin/python
10:24:44 INFO - Installing distribute.............................................................................................................................................................................................done.
10:24:46 INFO - Installing pip.................done.
10:24:46 INFO - Return code: 0
10:24:46 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv
10:24:46 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:24:46 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
10:24:46 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:24:46 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:24:46 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
10:24:46 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:24:46 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'pip>=1.5']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fdd35f06c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1ab56c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1b669a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1bf5ac0>, '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 0x1bf69a0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1bf6e50>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059', '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', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/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
10:24:46 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'pip>=1.5'] in /builds/slave/test/build
10:24:46 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub pip>=1.5
10:24:46 INFO - Using env: {'DISPLAY': ':0',
10:24:46 INFO - 'HOME': '/home/cltbld',
10:24:46 INFO - 'LANG': 'en_US.UTF-8',
10:24:46 INFO - 'LANGUAGE': 'en_US:en',
10:24:46 INFO - 'LOGNAME': 'cltbld',
10:24:46 INFO - 'MAIL': '/var/mail/cltbld',
10:24:46 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
10:24:46 INFO - 'MOZ_NO_REMOTE': '1',
10:24:46 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
10:24:46 INFO - 'NO_EM_RESTART': '1',
10:24:46 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
10:24:46 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
10:24:46 INFO - 'PWD': '/builds/slave/test',
10:24:46 INFO - 'SHELL': '/bin/bash',
10:24:46 INFO - 'SHLVL': '1',
10:24:46 INFO - 'TERM': 'linux',
10:24:46 INFO - 'TMOUT': '86400',
10:24:46 INFO - 'USER': 'cltbld',
10:24:46 INFO - 'XDG_SESSION_COOKIE': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059',
10:24:46 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
10:24:46 INFO - '_': '/tools/buildbot/bin/python'}
10:24:46 INFO - Ignoring indexes: https://pypi.python.org/simple/
10:24:46 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
10:24:46 INFO - Cleaning up...
10:24:46 INFO - Return code: 0
10:24:46 INFO - Installing psutil>=0.7.1 into virtualenv /builds/slave/test/build/venv
10:24:46 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:24:46 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
10:24:46 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:24:46 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:24:46 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
10:24:46 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:24:46 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'psutil>=0.7.1']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fdd35f06c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1ab56c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1b669a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1bf5ac0>, '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 0x1bf69a0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1bf6e50>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059', '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', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/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
10:24:46 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'psutil>=0.7.1'] in /builds/slave/test/build
10:24:46 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub psutil>=0.7.1
10:24:46 INFO - Using env: {'DISPLAY': ':0',
10:24:46 INFO - 'HOME': '/home/cltbld',
10:24:46 INFO - 'LANG': 'en_US.UTF-8',
10:24:46 INFO - 'LANGUAGE': 'en_US:en',
10:24:46 INFO - 'LOGNAME': 'cltbld',
10:24:46 INFO - 'MAIL': '/var/mail/cltbld',
10:24:46 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
10:24:46 INFO - 'MOZ_NO_REMOTE': '1',
10:24:46 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
10:24:46 INFO - 'NO_EM_RESTART': '1',
10:24:46 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
10:24:46 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
10:24:46 INFO - 'PWD': '/builds/slave/test',
10:24:46 INFO - 'SHELL': '/bin/bash',
10:24:46 INFO - 'SHLVL': '1',
10:24:46 INFO - 'TERM': 'linux',
10:24:46 INFO - 'TMOUT': '86400',
10:24:46 INFO - 'USER': 'cltbld',
10:24:46 INFO - 'XDG_SESSION_COOKIE': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059',
10:24:46 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
10:24:46 INFO - '_': '/tools/buildbot/bin/python'}
10:24:46 INFO - Ignoring indexes: https://pypi.python.org/simple/
10:24:46 INFO - Downloading/unpacking psutil>=0.7.1
10:24:46 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
10:24:46 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
10:24:46 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
10:24:46 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
10:24:46 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
10:24:46 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
10:24:48 INFO - Creating supposed download cache at /builds/slave/test/build/venv/cache
10:24:48 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fpsutil-3.1.1.tar.gz
10:24:48 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/psutil/setup.py) egg_info for package psutil
10:24:48 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build'
10:24:48 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects
...
10:24:48 INFO - Installing collected packages: psutil
10:24:48 INFO - Running setup.py install for psutil
10:24:48 INFO - building 'psutil._psutil_linux' extension
10:24:48 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
10:24:48 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
10:24:48 INFO - building 'psutil._psutil_posix' extension
10:24:48 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
10:24:48 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
10:24:48 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build'
10:24:48 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ...
10:24:48 INFO - Successfully installed psutil
10:24:48 INFO - Cleaning up...
10:24:48 INFO - Return code: 0
10:24:48 INFO - Installing mozsystemmonitor==0.0.0 into virtualenv /builds/slave/test/build/venv
10:24:48 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')]}
10:24:49 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
10:24:49 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:24:49 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')]}
10:24:49 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
10:24:49 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:24:49 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'mozsystemmonitor==0.0.0']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fdd35f06c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1ab56c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1b669a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1bf5ac0>, '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 0x1bf69a0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1bf6e50>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059', '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', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/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
10:24:49 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'mozsystemmonitor==0.0.0'] in /builds/slave/test/build
10:24:49 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub mozsystemmonitor==0.0.0
10:24:49 INFO - Using env: {'DISPLAY': ':0',
10:24:49 INFO - 'HOME': '/home/cltbld',
10:24:49 INFO - 'LANG': 'en_US.UTF-8',
10:24:49 INFO - 'LANGUAGE': 'en_US:en',
10:24:49 INFO - 'LOGNAME': 'cltbld',
10:24:49 INFO - 'MAIL': '/var/mail/cltbld',
10:24:49 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
10:24:49 INFO - 'MOZ_NO_REMOTE': '1',
10:24:49 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
10:24:49 INFO - 'NO_EM_RESTART': '1',
10:24:49 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
10:24:49 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
10:24:49 INFO - 'PWD': '/builds/slave/test',
10:24:49 INFO - 'SHELL': '/bin/bash',
10:24:49 INFO - 'SHLVL': '1',
10:24:49 INFO - 'TERM': 'linux',
10:24:49 INFO - 'TMOUT': '86400',
10:24:49 INFO - 'USER': 'cltbld',
10:24:49 INFO - 'XDG_SESSION_COOKIE': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059',
10:24:49 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
10:24:49 INFO - '_': '/tools/buildbot/bin/python'}
10:24:49 INFO - Ignoring indexes: https://pypi.python.org/simple/
10:24:49 INFO - Downloading/unpacking mozsystemmonitor==0.0.0
10:24:49 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
10:24:49 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
10:24:49 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
10:24:49 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
10:24:49 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
10:24:49 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
10:24:50 INFO - Downloading mozsystemmonitor-0.0.tar.gz
10:24:50 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fmozsystemmonitor-0.0.tar.gz
10:24:50 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/mozsystemmonitor/setup.py) egg_info for package mozsystemmonitor
10:24:50 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=0.7.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.0.0)
10:24:50 INFO - Installing collected packages: mozsystemmonitor
10:24:50 INFO - Running setup.py install for mozsystemmonitor
10:24:51 INFO - Successfully installed mozsystemmonitor
10:24:51 INFO - Cleaning up...
10:24:51 INFO - Return code: 0
10:24:51 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv
10:24:51 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')]}
10:24:51 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
10:24:51 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:24:51 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')]}
10:24:51 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
10:24:51 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:24:51 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'blobuploader==1.2.4']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fdd35f06c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1ab56c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1b669a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1bf5ac0>, '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 0x1bf69a0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1bf6e50>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059', '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', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/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
10:24:51 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'blobuploader==1.2.4'] in /builds/slave/test/build
10:24:51 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub blobuploader==1.2.4
10:24:51 INFO - Using env: {'DISPLAY': ':0',
10:24:51 INFO - 'HOME': '/home/cltbld',
10:24:51 INFO - 'LANG': 'en_US.UTF-8',
10:24:51 INFO - 'LANGUAGE': 'en_US:en',
10:24:51 INFO - 'LOGNAME': 'cltbld',
10:24:51 INFO - 'MAIL': '/var/mail/cltbld',
10:24:51 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
10:24:51 INFO - 'MOZ_NO_REMOTE': '1',
10:24:51 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
10:24:51 INFO - 'NO_EM_RESTART': '1',
10:24:51 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
10:24:51 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
10:24:51 INFO - 'PWD': '/builds/slave/test',
10:24:51 INFO - 'SHELL': '/bin/bash',
10:24:51 INFO - 'SHLVL': '1',
10:24:51 INFO - 'TERM': 'linux',
10:24:51 INFO - 'TMOUT': '86400',
10:24:51 INFO - 'USER': 'cltbld',
10:24:51 INFO - 'XDG_SESSION_COOKIE': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059',
10:24:51 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
10:24:51 INFO - '_': '/tools/buildbot/bin/python'}
10:24:51 INFO - Ignoring indexes: https://pypi.python.org/simple/
10:24:51 INFO - Downloading/unpacking blobuploader==1.2.4
10:24:51 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
10:24:51 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
10:24:51 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
10:24:51 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
10:24:51 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
10:24:51 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
10:24:52 INFO - Downloading blobuploader-1.2.4.tar.gz
10:24:52 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fblobuploader-1.2.4.tar.gz
10:24:52 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blobuploader/setup.py) egg_info for package blobuploader
10:24:52 INFO - Downloading/unpacking requests==1.2.3. (from blobuploader==1.2.4)
10:24:52 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
10:24:52 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
10:24:52 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
10:24:52 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
10:24:52 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
10:24:52 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
10:24:53 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Frequests-1.2.3.tar.gz
10:24:53 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests
10:24:53 INFO - Downloading/unpacking docopt==0.6.1 (from blobuploader==1.2.4)
10:24: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
10:24: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
10:24: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
10:24: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
10:24: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
10:24: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
10:24:53 INFO - Downloading docopt-0.6.1.tar.gz
10:24:53 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fdocopt-0.6.1.tar.gz
10:24:53 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/docopt/setup.py) egg_info for package docopt
10:24:53 INFO - Installing collected packages: blobuploader, requests, docopt
10:24:53 INFO - Running setup.py install for blobuploader
10:24:53 INFO - changing mode of build/scripts-2.7/blobberc.py from 664 to 775
10:24:53 INFO - changing mode of /builds/slave/test/build/venv/bin/blobberc.py to 775
10:24:53 INFO - Running setup.py install for requests
10:24:54 INFO - Running setup.py install for docopt
10:24:54 INFO - Successfully installed blobuploader requests docopt
10:24:54 INFO - Cleaning up...
10:24:54 INFO - Return code: 0
10:24:54 INFO - Installing None into virtualenv /builds/slave/test/build/venv
10:24:54 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:24:54 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
10:24:54 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:24:54 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:24:54 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
10:24:54 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:24:54 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fdd35f06c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1ab56c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1b669a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1bf5ac0>, '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 0x1bf69a0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1bf6e50>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build/tests/config', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059', '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', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/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
10:24:54 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/config
10:24:54 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --no-deps --download-cache /builds/slave/test/build/venv/cache --timeout 120 -r /builds/slave/test/build/tests/config/mozbase_requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub
10:24:54 INFO - Using env: {'DISPLAY': ':0',
10:24:54 INFO - 'HOME': '/home/cltbld',
10:24:54 INFO - 'LANG': 'en_US.UTF-8',
10:24:54 INFO - 'LANGUAGE': 'en_US:en',
10:24:54 INFO - 'LOGNAME': 'cltbld',
10:24:54 INFO - 'MAIL': '/var/mail/cltbld',
10:24:54 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
10:24:54 INFO - 'MOZ_NO_REMOTE': '1',
10:24:54 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
10:24:54 INFO - 'NO_EM_RESTART': '1',
10:24:54 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
10:24:54 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
10:24:54 INFO - 'PWD': '/builds/slave/test',
10:24:54 INFO - 'SHELL': '/bin/bash',
10:24:54 INFO - 'SHLVL': '1',
10:24:54 INFO - 'TERM': 'linux',
10:24:54 INFO - 'TMOUT': '86400',
10:24:54 INFO - 'USER': 'cltbld',
10:24:54 INFO - 'XDG_SESSION_COOKIE': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059',
10:24:54 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
10:24:54 INFO - '_': '/tools/buildbot/bin/python'}
10:24:54 INFO - Ignoring indexes: https://pypi.python.org/simple/
10:24:54 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser
10:24:54 INFO - Running setup.py (path:/tmp/pip-VLbhDF-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser
10:24:54 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash
10:24:54 INFO - Running setup.py (path:/tmp/pip-kwXeI2-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash
10:24:54 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug
10:24:54 INFO - Running setup.py (path:/tmp/pip-_71cVp-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug
10:24:54 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice
10:24:54 INFO - Running setup.py (path:/tmp/pip-6WskUG-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice
10:24:54 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile
10:24:54 INFO - Running setup.py (path:/tmp/pip-a3Rcsk-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile
10:24:54 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd
10:24:54 INFO - Running setup.py (path:/tmp/pip-P3bPTa-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd
10:24:54 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo
10:24:54 INFO - Running setup.py (path:/tmp/pip-tWiVJN-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo
10:24:54 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall
10:24:54 INFO - Running setup.py (path:/tmp/pip-U6hILu-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall
10:24:55 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak
10:24:55 INFO - Running setup.py (path:/tmp/pip-ZxJdVD-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak
10:24:55 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog
10:24:55 INFO - Running setup.py (path:/tmp/pip-vXMJNu-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog
10:24:55 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork
10:24:55 INFO - Running setup.py (path:/tmp/pip-EC0kUH-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork
10:24:55 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess
10:24:55 INFO - Running setup.py (path:/tmp/pip-UiXgz_-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess
10:24:55 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile
10:24:55 INFO - Running setup.py (path:/tmp/pip-wISMgZ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile
10:24:55 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner
10:24:55 INFO - Running setup.py (path:/tmp/pip-5kZYJv-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner
10:24:55 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot
10:24:55 INFO - Running setup.py (path:/tmp/pip-uxDiCd-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot
10:24:55 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest
10:24:55 INFO - Running setup.py (path:/tmp/pip-i7p43c-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest
10:24:55 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion
10:24:55 INFO - Running setup.py (path:/tmp/pip-bhit39-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion
10:24:55 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion
10:24:55 INFO - Running setup.py install for manifestparser
10:24:55 INFO - Installing manifestparser script to /builds/slave/test/build/venv/bin
10:24:55 INFO - Running setup.py install for mozcrash
10:24:55 INFO - Running setup.py install for mozdebug
10:24:55 INFO - Running setup.py install for mozdevice
10:24:56 INFO - Installing sutini script to /builds/slave/test/build/venv/bin
10:24:56 INFO - Installing dm script to /builds/slave/test/build/venv/bin
10:24:56 INFO - Running setup.py install for mozfile
10:24:56 INFO - Running setup.py install for mozhttpd
10:24:56 INFO - Installing mozhttpd script to /builds/slave/test/build/venv/bin
10:24:56 INFO - Running setup.py install for mozinfo
10:24:56 INFO - Installing mozinfo script to /builds/slave/test/build/venv/bin
10:24:56 INFO - Running setup.py install for mozInstall
10:24:56 INFO - Installing moz_remove_from_system script to /builds/slave/test/build/venv/bin
10:24:56 INFO - Installing mozuninstall script to /builds/slave/test/build/venv/bin
10:24:56 INFO - Installing mozinstall script to /builds/slave/test/build/venv/bin
10:24:56 INFO - Installing moz_add_to_system script to /builds/slave/test/build/venv/bin
10:24:56 INFO - Running setup.py install for mozleak
10:24:56 INFO - Running setup.py install for mozlog
10:24:56 INFO - Installing structlog script to /builds/slave/test/build/venv/bin
10:24:56 INFO - Running setup.py install for moznetwork
10:24:56 INFO - Installing moznetwork script to /builds/slave/test/build/venv/bin
10:24:56 INFO - Running setup.py install for mozprocess
10:24:56 INFO - Running setup.py install for mozprofile
10:24:56 INFO - Installing mozprofile script to /builds/slave/test/build/venv/bin
10:24:56 INFO - Installing diff-profiles script to /builds/slave/test/build/venv/bin
10:24:56 INFO - Installing view-profile script to /builds/slave/test/build/venv/bin
10:24:57 INFO - Running setup.py install for mozrunner
10:24:57 INFO - Installing mozrunner script to /builds/slave/test/build/venv/bin
10:24:57 INFO - Running setup.py install for mozscreenshot
10:24:57 INFO - Running setup.py install for moztest
10:24:57 INFO - Running setup.py install for mozversion
10:24:57 INFO - Installing mozversion script to /builds/slave/test/build/venv/bin
10:24:57 INFO - Successfully installed manifestparser mozcrash mozdebug mozdevice mozfile mozhttpd mozinfo mozInstall mozleak mozlog moznetwork mozprocess mozprofile mozrunner mozscreenshot moztest mozversion
10:24:57 INFO - Cleaning up...
10:24:57 INFO - Return code: 0
10:24:57 INFO - Installing None into virtualenv /builds/slave/test/build/venv
10:24:57 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')]}
10:24:57 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
10:24:57 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:24:57 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')]}
10:24:57 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
10:24:57 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:24:57 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fdd35f06c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1ab56c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1b669a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1bf5ac0>, '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 0x1bf69a0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1bf6e50>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build/tests/config', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059', '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', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/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
10:24:57 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/config
10:24:57 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 -r /builds/slave/test/build/tests/config/mozbase_requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub
10:24:57 INFO - Using env: {'DISPLAY': ':0',
10:24:57 INFO - 'HOME': '/home/cltbld',
10:24:57 INFO - 'LANG': 'en_US.UTF-8',
10:24:57 INFO - 'LANGUAGE': 'en_US:en',
10:24:57 INFO - 'LOGNAME': 'cltbld',
10:24:57 INFO - 'MAIL': '/var/mail/cltbld',
10:24:57 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
10:24:57 INFO - 'MOZ_NO_REMOTE': '1',
10:24:57 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
10:24:57 INFO - 'NO_EM_RESTART': '1',
10:24:57 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
10:24:57 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
10:24:57 INFO - 'PWD': '/builds/slave/test',
10:24:57 INFO - 'SHELL': '/bin/bash',
10:24:57 INFO - 'SHLVL': '1',
10:24:57 INFO - 'TERM': 'linux',
10:24:57 INFO - 'TMOUT': '86400',
10:24:57 INFO - 'USER': 'cltbld',
10:24:57 INFO - 'XDG_SESSION_COOKIE': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059',
10:24:57 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
10:24:57 INFO - '_': '/tools/buildbot/bin/python'}
10:24:57 INFO - Ignoring indexes: https://pypi.python.org/simple/
10:24:57 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser
10:24:57 INFO - Running setup.py (path:/tmp/pip-eGBJ04-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser
10:24:57 INFO - Requirement already satisfied (use --upgrade to upgrade): manifestparser==1.1 from file:///builds/slave/test/build/tests/mozbase/manifestparser in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 1))
10:24:57 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash
10:24:57 INFO - Running setup.py (path:/tmp/pip-9ilcfj-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash
10:24:57 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash==0.16 from file:///builds/slave/test/build/tests/mozbase/mozcrash in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2))
10:24:57 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug
10:24:57 INFO - Running setup.py (path:/tmp/pip-X_XYmp-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug
10:24:57 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdebug==0.1 from file:///builds/slave/test/build/tests/mozbase/mozdebug in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 3))
10:24:57 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice
10:24:57 INFO - Running setup.py (path:/tmp/pip-Mbw2nb-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice
10:24:57 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdevice==0.47 from file:///builds/slave/test/build/tests/mozbase/mozdevice in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4))
10:24:57 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile
10:24:57 INFO - Running setup.py (path:/tmp/pip-Mbd13x-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile
10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile==1.2 from file:///builds/slave/test/build/tests/mozbase/mozfile in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 5))
10:24:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd
10:24:58 INFO - Running setup.py (path:/tmp/pip-Z_ow0o-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd
10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd==0.7 from file:///builds/slave/test/build/tests/mozbase/mozhttpd in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 6))
10:24:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo
10:24:58 INFO - Running setup.py (path:/tmp/pip-JtMuIc-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo
10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo==0.9 from file:///builds/slave/test/build/tests/mozbase/mozinfo in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 7))
10:24:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall
10:24:58 INFO - Running setup.py (path:/tmp/pip-OSX7zM-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall
10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozInstall==1.12 from file:///builds/slave/test/build/tests/mozbase/mozinstall in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 8))
10:24:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak
10:24:58 INFO - Running setup.py (path:/tmp/pip-_YJInS-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak
10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozleak==0.1 from file:///builds/slave/test/build/tests/mozbase/mozleak in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 9))
10:24:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog
10:24:58 INFO - Running setup.py (path:/tmp/pip-svXFzb-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog
10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog==3.0 from file:///builds/slave/test/build/tests/mozbase/mozlog in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10))
10:24:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork
10:24:58 INFO - Running setup.py (path:/tmp/pip-9OGMId-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork
10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork==0.27 from file:///builds/slave/test/build/tests/mozbase/moznetwork in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 11))
10:24:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess
10:24:58 INFO - Running setup.py (path:/tmp/pip-HxFp8u-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess
10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess==0.22 from file:///builds/slave/test/build/tests/mozbase/mozprocess in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 12))
10:24:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile
10:24:58 INFO - Running setup.py (path:/tmp/pip-Y9qkD1-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile
10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile==0.27 from file:///builds/slave/test/build/tests/mozbase/mozprofile in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 13))
10:24:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner
10:24:58 INFO - Running setup.py (path:/tmp/pip-8d6U3J-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner
10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozrunner==6.11 from file:///builds/slave/test/build/tests/mozbase/mozrunner in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 14))
10:24:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot
10:24:58 INFO - Running setup.py (path:/tmp/pip-tWRg2V-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot
10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozscreenshot==0.1 from file:///builds/slave/test/build/tests/mozbase/mozscreenshot in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 15))
10:24:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest
10:24:58 INFO - Running setup.py (path:/tmp/pip-CHHNGr-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest
10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): moztest==0.7 from file:///builds/slave/test/build/tests/mozbase/moztest in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 16))
10:24:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion
10:24:58 INFO - Running setup.py (path:/tmp/pip-g_bbaO-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion
10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion==1.4 from file:///builds/slave/test/build/tests/mozbase/mozversion in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 17))
10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozcrash==0.16->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2))
10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozcrash==0.16->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2))
10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozdebug==0.1->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 3))
10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork>=0.24 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozdevice==0.47->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4))
10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.19 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozdevice==0.47->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4))
10:24:58 INFO - Downloading/unpacking blessings>=1.3 (from mozlog==3.0->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10))
10:24: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
10:24: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
10:24: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
10:24: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
10:24: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
10:24: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
10:25:00 INFO - Downloading blessings-1.5.1.tar.gz
10:25:00 INFO - Storing download in cache at /builds/slave/test/build/venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fblessings-1.5.1.tar.gz
10:25:00 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blessings/setup.py) egg_info for package blessings
10:25:00 INFO - Installing collected packages: blessings
10:25:00 INFO - Running setup.py install for blessings
10:25:00 INFO - Successfully installed blessings
10:25:00 INFO - Cleaning up...
10:25:00 INFO - Return code: 0
10:25:00 INFO - Done creating virtualenv /builds/slave/test/build/venv.
10:25:00 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze']
10:25:00 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze
10:25:01 INFO - Reading from file tmpfile_stdout
10:25:01 INFO - Current package versions:
10:25:01 INFO - argparse == 1.2.1
10:25:01 INFO - blessings == 1.5.1
10:25:01 INFO - blobuploader == 1.2.4
10:25:01 INFO - docopt == 0.6.1
10:25:01 INFO - manifestparser == 1.1
10:25:01 INFO - mozInstall == 1.12
10:25:01 INFO - mozcrash == 0.16
10:25:01 INFO - mozdebug == 0.1
10:25:01 INFO - mozdevice == 0.47
10:25:01 INFO - mozfile == 1.2
10:25:01 INFO - mozhttpd == 0.7
10:25:01 INFO - mozinfo == 0.9
10:25:01 INFO - mozleak == 0.1
10:25:01 INFO - mozlog == 3.0
10:25:01 INFO - moznetwork == 0.27
10:25:01 INFO - mozprocess == 0.22
10:25:01 INFO - mozprofile == 0.27
10:25:01 INFO - mozrunner == 6.11
10:25:01 INFO - mozscreenshot == 0.1
10:25:01 INFO - mozsystemmonitor == 0.0
10:25:01 INFO - moztest == 0.7
10:25:01 INFO - mozversion == 1.4
10:25:01 INFO - psutil == 3.1.1
10:25:01 INFO - requests == 1.2.3
10:25:01 INFO - wsgiref == 0.1.2
10:25:01 INFO - Installing None into virtualenv /builds/slave/test/build/venv
10:25: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')]}
10:25:01 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
10:25:01 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:25: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')]}
10:25:01 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
10:25:01 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:25:01 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test/build/tests/talos/requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fdd35f06c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1ab56c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1b669a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1bf5ac0>, '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 0x1bf69a0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1bf6e50>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build/tests/talos', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059', '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', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/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
10:25:01 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test/build/tests/talos/requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/talos
10:25:01 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 -r /builds/slave/test/build/tests/talos/requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub
10:25:01 INFO - Using env: {'DISPLAY': ':0',
10:25:01 INFO - 'HOME': '/home/cltbld',
10:25:01 INFO - 'LANG': 'en_US.UTF-8',
10:25:01 INFO - 'LANGUAGE': 'en_US:en',
10:25:01 INFO - 'LOGNAME': 'cltbld',
10:25:01 INFO - 'MAIL': '/var/mail/cltbld',
10:25:01 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
10:25:01 INFO - 'MOZ_NO_REMOTE': '1',
10:25:01 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
10:25:01 INFO - 'NO_EM_RESTART': '1',
10:25:01 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
10:25:01 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
10:25:01 INFO - 'PWD': '/builds/slave/test',
10:25:01 INFO - 'SHELL': '/bin/bash',
10:25:01 INFO - 'SHLVL': '1',
10:25:01 INFO - 'TERM': 'linux',
10:25:01 INFO - 'TMOUT': '86400',
10:25:01 INFO - 'USER': 'cltbld',
10:25:01 INFO - 'XDG_SESSION_COOKIE': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059',
10:25:01 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
10:25:01 INFO - '_': '/tools/buildbot/bin/python'}
10:25:01 INFO - Ignoring indexes: https://pypi.python.org/simple/
10:25:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash>=0.15 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 1))
10:25:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.2 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 2))
10:25:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd>=0.7 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 3))
10:25:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo>=0.8 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 4))
10:25:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.22 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 5))
10:25:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion>=1.3 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 6))
10:25:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile>=0.25 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 7))
10:25:01 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 8))
10:25:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozcrash>=0.15->-r /builds/slave/test/build/tests/talos/requirements.txt (line 1))
10:25:01 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork>=0.24 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozhttpd>=0.7->-r /builds/slave/test/build/tests/talos/requirements.txt (line 3))
10:25:01 INFO - Requirement already satisfied (use --upgrade to upgrade): blessings>=1.3 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozlog>=3.0->mozcrash>=0.15->-r /builds/slave/test/build/tests/talos/requirements.txt (line 1))
10:25:01 INFO - Cleaning up...
10:25:01 INFO - Return code: 0
10:25:01 INFO - Running post-action listener: _resource_record_post_action
10:25:01 INFO - Running post-action listener: _start_resource_monitoring
10:25:01 INFO - Starting resource monitoring.
10:25:01 INFO - #####
10:25:01 INFO - ##### Running install step.
10:25:01 INFO - #####
10:25:01 INFO - Running pre-action listener: _resource_record_pre_action
10:25:01 INFO - Running main action method: install
10:25:01 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze']
10:25:01 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze
10:25:01 INFO - Reading from file tmpfile_stdout
10:25:01 INFO - Detecting whether we're running mozinstall >=1.0...
10:25:01 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h']
10:25:01 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h
10:25:01 INFO - Reading from file tmpfile_stdout
10:25:01 INFO - Output received:
10:25:01 INFO - Usage: mozinstall [options] installer
10:25:01 INFO - Options:
10:25:01 INFO - -h, --help show this help message and exit
10:25:01 INFO - -d DEST, --destination=DEST
10:25:01 INFO - Directory to install application into. [default:
10:25:01 INFO - "/builds/slave/test"]
10:25:01 INFO - --app=APP Application being installed. [default: firefox]
10:25:01 INFO - mkdir: /builds/slave/test/build/application
10:25:01 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2', '--destination', '/builds/slave/test/build/application']
10:25:01 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 --destination /builds/slave/test/build/application
10:25:15 INFO - Reading from file tmpfile_stdout
10:25:15 INFO - Output received:
10:25:15 INFO - /builds/slave/test/build/application/firefox/firefox
10:25:15 INFO - Running post-action listener: _resource_record_post_action
10:25:15 INFO - #####
10:25:15 INFO - ##### Running run-tests step.
10:25:15 INFO - #####
10:25:15 INFO - Running pre-action listener: _resource_record_pre_action
10:25:15 INFO - Running main action method: run_tests
10:25:15 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version']
10:25:15 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version
10:25:15 INFO - Python 2.7.3
10:25:15 INFO - Return code: 0
10:25:15 INFO - grabbing minidump binary from tooltool
10:25:15 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:25:15 INFO - retry: Calling run_command with args: (['/tools/tooltool.py', '--url', 'https://api.pub.build.mozilla.org/tooltool/', '--authentication-file', '/builds/relengapi.tok', 'fetch', '-m', '/builds/slave/test/build/tests/config/tooltool-manifests/linux64/releng.manifest', '-o', '-c', '/builds/tooltool_cache'],), kwargs: {'error_list': [{'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1bf5ac0>, '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 0x1bf69a0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1bf6e50>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1
10:25:15 INFO - Running command: ['/tools/tooltool.py', '--url', 'https://api.pub.build.mozilla.org/tooltool/', '--authentication-file', '/builds/relengapi.tok', 'fetch', '-m', '/builds/slave/test/build/tests/config/tooltool-manifests/linux64/releng.manifest', '-o', '-c', '/builds/tooltool_cache'] in /builds/slave/test/build
10:25:15 INFO - Copy/paste: /tools/tooltool.py --url https://api.pub.build.mozilla.org/tooltool/ --authentication-file /builds/relengapi.tok fetch -m /builds/slave/test/build/tests/config/tooltool-manifests/linux64/releng.manifest -o -c /builds/tooltool_cache
10:25:15 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache
10:25:15 INFO - Return code: 0
10:25:15 INFO - Chmoding /builds/slave/test/build/linux64-minidump_stackwalk to 0755
10:25:15 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir
10:25:15 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir
10:25:15 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/linux64-minidump_stackwalk
10:25:15 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir
10:25:15 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--debug', '--branchName', 'Mozilla-Inbound-Non-PGO', '--suite', 'other', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-048', '--webServer', 'localhost'] in /builds/slave/test/build
10:25:15 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/tests/talos/talos/run_tests.py --debug --branchName Mozilla-Inbound-Non-PGO --suite other --executablePath /builds/slave/test/build/application/firefox/firefox --symbolsPath https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.crashreporter-symbols.zip --title talos-linux64-ix-048 --webServer localhost
10:25:15 INFO - Using env: {'DISPLAY': ':0',
10:25:15 INFO - 'HOME': '/home/cltbld',
10:25:15 INFO - 'LANG': 'en_US.UTF-8',
10:25:15 INFO - 'LANGUAGE': 'en_US:en',
10:25:15 INFO - 'LOGNAME': 'cltbld',
10:25:15 INFO - 'MAIL': '/var/mail/cltbld',
10:25:15 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir',
10:25:15 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk',
10:25:15 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
10:25:15 INFO - 'MOZ_NO_REMOTE': '1',
10:25:15 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir',
10:25:15 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
10:25:15 INFO - 'NO_EM_RESTART': '1',
10:25:15 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
10:25:15 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
10:25:15 INFO - 'PWD': '/builds/slave/test',
10:25:15 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos',
10:25:15 INFO - 'SHELL': '/bin/bash',
10:25:15 INFO - 'SHLVL': '1',
10:25:15 INFO - 'TERM': 'linux',
10:25:15 INFO - 'TMOUT': '86400',
10:25:15 INFO - 'USER': 'cltbld',
10:25:15 INFO - 'XDG_SESSION_COOKIE': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059',
10:25:15 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
10:25:15 INFO - '_': '/tools/buildbot/bin/python'}
10:25:15 INFO - Calling ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--debug', '--branchName', 'Mozilla-Inbound-Non-PGO', '--suite', 'other', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-048', '--webServer', 'localhost'] with output_timeout 3600
10:25:16 INFO - mozversion INFO | application_buildid: 20151112100440
10:25:16 INFO - mozversion INFO | application_changeset: 756632e20aa46ce0b2feebdf6f04e6dacdc09811
10:25:16 INFO - mozversion INFO | application_display_name: Nightly
10:25:16 INFO - mozversion INFO | application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384}
10:25:16 INFO - mozversion INFO | application_name: Firefox
10:25:16 INFO - mozversion INFO | application_remotingname: firefox
10:25:16 INFO - mozversion INFO | application_repository: https://hg.mozilla.org/integration/mozilla-inbound
10:25:16 INFO - mozversion INFO | application_vendor: Mozilla
10:25:16 INFO - mozversion INFO | application_version: 45.0a1
10:25:16 INFO - mozversion INFO | platform_buildid: 20151112100440
10:25:16 INFO - mozversion INFO | platform_changeset: 756632e20aa46ce0b2feebdf6f04e6dacdc09811
10:25:16 INFO - mozversion INFO | platform_repository: https://hg.mozilla.org/integration/mozilla-inbound
10:25:16 INFO - mozversion INFO | platform_version: 45.0a1
10:25:16 INFO - 2015-11-12 10:25:16,112 DEBUG : using testdate: 1447352716
10:25:16 INFO - 2015-11-12 10:25:16,112 DEBUG : actual date: 1447352716
10:25:16 INFO - 2015-11-12 10:25:16,119 INFO : starting webserver on 'localhost:53596'
10:25:16 INFO - 2015-11-12 10:25:16,120 INFO : Starting test suite talos-linux64-ix-048
10:25:16 INFO - 2015-11-12 10:25:16,120 INFO : Starting test a11yr
10:25:16 INFO - 2015-11-12 10:25:16,120 DEBUG : operating with platform_type : linux_
10:25:16 INFO - 2015-11-12 10:25:16,121 INFO : Initialising browser for a11yr test...
10:25:16 INFO - 2015-11-12 10:25:16,127 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_5w2w/profile http://localhost:53596/getInfo.html
10:25:22 INFO - 2015-11-12 10:25:22,608 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
10:25:22 INFO - 2015-11-12 10:25:22,608 DEBUG : BROWSER_OUTPUT: colorDepth:24
10:25:22 INFO - 2015-11-12 10:25:22,608 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697
10:25:22 INFO - 2015-11-12 10:25:22,608 DEBUG : BROWSER_OUTPUT: __metrics
10:25:22 INFO - 2015-11-12 10:25:22,724 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]
10:25:24 INFO - 2015-11-12 10:25:24,048 INFO : Browser initialized.
10:25:24 INFO - 2015-11-12 10:25:24,049 INFO : Running cycle 1/1 for a11yr test...
10:25:24 INFO - 2015-11-12 10:25:24,049 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_5w2w/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/a11y/a11y.manifest.develop -tpchrome -tpmozafterpaint -tpnoisy -tpcycles 1 -tppagecycles 25
10:25:35 INFO - 2015-11-12 10:25:35,987 DEBUG : BROWSER_OUTPUT: RSS: Main: 141590528
10:25:35 INFO - 2015-11-12 10:25:35,987 DEBUG : BROWSER_OUTPUT:
10:25:37 INFO - 2015-11-12 10:25:37,412 DEBUG : BROWSER_OUTPUT:
10:25:37 INFO - 2015-11-12 10:25:37,412 DEBUG : BROWSER_OUTPUT: (firefox:29721): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed
10:25:37 INFO - 2015-11-12 10:25:37,432 DEBUG : BROWSER_OUTPUT: Cycle 1(1): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:25:38 INFO - 2015-11-12 10:25:38,048 DEBUG : BROWSER_OUTPUT: RSS: Main: 178913280
10:25:38 INFO - 2015-11-12 10:25:38,048 DEBUG : BROWSER_OUTPUT:
10:25:39 INFO - 2015-11-12 10:25:39,606 DEBUG : BROWSER_OUTPUT: Cycle 1(2): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:25:40 INFO - 2015-11-12 10:25:40,294 DEBUG : BROWSER_OUTPUT: RSS: Main: 183635968
10:25:40 INFO - 2015-11-12 10:25:40,295 DEBUG : BROWSER_OUTPUT:
10:25:41 INFO - 2015-11-12 10:25:41,861 DEBUG : BROWSER_OUTPUT: Cycle 1(3): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:25:42 INFO - 2015-11-12 10:25:42,548 DEBUG : BROWSER_OUTPUT: RSS: Main: 180060160
10:25:42 INFO - 2015-11-12 10:25:42,548 DEBUG : BROWSER_OUTPUT:
10:25:44 INFO - 2015-11-12 10:25:44,201 DEBUG : BROWSER_OUTPUT: Cycle 1(4): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:25:44 INFO - 2015-11-12 10:25:44,909 DEBUG : BROWSER_OUTPUT: RSS: Main: 182444032
10:25:44 INFO - 2015-11-12 10:25:44,910 DEBUG : BROWSER_OUTPUT:
10:25:46 INFO - 2015-11-12 10:25:46,516 DEBUG : BROWSER_OUTPUT: Cycle 1(5): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:25:47 INFO - 2015-11-12 10:25:47,203 DEBUG : BROWSER_OUTPUT: RSS: Main: 179429376
10:25:47 INFO - 2015-11-12 10:25:47,204 DEBUG : BROWSER_OUTPUT:
10:25:48 INFO - 2015-11-12 10:25:48,729 DEBUG : BROWSER_OUTPUT: Cycle 1(6): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:25:49 INFO - 2015-11-12 10:25:49,416 DEBUG : BROWSER_OUTPUT: RSS: Main: 180666368
10:25:49 INFO - 2015-11-12 10:25:49,416 DEBUG : BROWSER_OUTPUT:
10:25:50 INFO - 2015-11-12 10:25:50,974 DEBUG : BROWSER_OUTPUT: Cycle 1(7): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:25:51 INFO - 2015-11-12 10:25:51,669 DEBUG : BROWSER_OUTPUT: RSS: Main: 180920320
10:25:51 INFO - 2015-11-12 10:25:51,669 DEBUG : BROWSER_OUTPUT:
10:25:53 INFO - 2015-11-12 10:25:53,200 DEBUG : BROWSER_OUTPUT: Cycle 1(8): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:25:53 INFO - 2015-11-12 10:25:53,890 DEBUG : BROWSER_OUTPUT: RSS: Main: 182583296
10:25:53 INFO - 2015-11-12 10:25:53,890 DEBUG : BROWSER_OUTPUT:
10:25:55 INFO - 2015-11-12 10:25:55,537 DEBUG : BROWSER_OUTPUT: Cycle 1(9): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:25:56 INFO - 2015-11-12 10:25:56,240 DEBUG : BROWSER_OUTPUT: RSS: Main: 182915072
10:25:56 INFO - 2015-11-12 10:25:56,240 DEBUG : BROWSER_OUTPUT:
10:25:57 INFO - 2015-11-12 10:25:57,770 DEBUG : BROWSER_OUTPUT: Cycle 1(10): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:25:58 INFO - 2015-11-12 10:25:58,464 DEBUG : BROWSER_OUTPUT: RSS: Main: 182398976
10:25:58 INFO - 2015-11-12 10:25:58,465 DEBUG : BROWSER_OUTPUT:
10:26:00 INFO - 2015-11-12 10:26:00,119 DEBUG : BROWSER_OUTPUT: Cycle 1(11): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:26:00 INFO - 2015-11-12 10:26:00,705 DEBUG : BROWSER_OUTPUT:
10:26:00 INFO - 2015-11-12 10:26:00,705 DEBUG : BROWSER_OUTPUT: (firefox:29721): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed
10:26:00 INFO - 2015-11-12 10:26:00,822 DEBUG : BROWSER_OUTPUT: RSS: Main: 184115200
10:26:00 INFO - 2015-11-12 10:26:00,822 DEBUG : BROWSER_OUTPUT:
10:26:02 INFO - 2015-11-12 10:26:02,453 DEBUG : BROWSER_OUTPUT: Cycle 1(12): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:26:03 INFO - 2015-11-12 10:26:03,155 DEBUG : BROWSER_OUTPUT: RSS: Main: 184434688
10:26:03 INFO - 2015-11-12 10:26:03,155 DEBUG : BROWSER_OUTPUT:
10:26:04 INFO - 2015-11-12 10:26:04,612 DEBUG : BROWSER_OUTPUT: Cycle 1(13): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:26:05 INFO - 2015-11-12 10:26:05,314 DEBUG : BROWSER_OUTPUT: RSS: Main: 181751808
10:26:05 INFO - 2015-11-12 10:26:05,314 DEBUG : BROWSER_OUTPUT:
10:26:06 INFO - 2015-11-12 10:26:06,886 DEBUG : BROWSER_OUTPUT: Cycle 1(14): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:26:07 INFO - 2015-11-12 10:26:07,576 DEBUG : BROWSER_OUTPUT: RSS: Main: 183201792
10:26:07 INFO - 2015-11-12 10:26:07,576 DEBUG : BROWSER_OUTPUT:
10:26:09 INFO - 2015-11-12 10:26:09,154 DEBUG : BROWSER_OUTPUT: Cycle 1(15): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:26:09 INFO - 2015-11-12 10:26:09,849 DEBUG : BROWSER_OUTPUT: RSS: Main: 181018624
10:26:09 INFO - 2015-11-12 10:26:09,849 DEBUG : BROWSER_OUTPUT:
10:26:11 INFO - 2015-11-12 10:26:11,407 DEBUG : BROWSER_OUTPUT: Cycle 1(16): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:26:12 INFO - 2015-11-12 10:26:12,098 DEBUG : BROWSER_OUTPUT: RSS: Main: 180850688
10:26:12 INFO - 2015-11-12 10:26:12,098 DEBUG : BROWSER_OUTPUT:
10:26:13 INFO - 2015-11-12 10:26:13,655 DEBUG : BROWSER_OUTPUT: Cycle 1(17): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:26:14 INFO - 2015-11-12 10:26:14,357 DEBUG : BROWSER_OUTPUT: RSS: Main: 181600256
10:26:14 INFO - 2015-11-12 10:26:14,357 DEBUG : BROWSER_OUTPUT:
10:26:15 INFO - 2015-11-12 10:26:15,915 DEBUG : BROWSER_OUTPUT: Cycle 1(18): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:26:16 INFO - 2015-11-12 10:26:16,610 DEBUG : BROWSER_OUTPUT: RSS: Main: 180981760
10:26:16 INFO - 2015-11-12 10:26:16,610 DEBUG : BROWSER_OUTPUT:
10:26:18 INFO - 2015-11-12 10:26:18,156 DEBUG : BROWSER_OUTPUT: Cycle 1(19): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:26:18 INFO - 2015-11-12 10:26:18,850 DEBUG : BROWSER_OUTPUT: RSS: Main: 182296576
10:26:18 INFO - 2015-11-12 10:26:18,850 DEBUG : BROWSER_OUTPUT:
10:26:20 INFO - 2015-11-12 10:26:20,397 DEBUG : BROWSER_OUTPUT: Cycle 1(20): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:26:21 INFO - 2015-11-12 10:26:21,099 DEBUG : BROWSER_OUTPUT: RSS: Main: 182370304
10:26:21 INFO - 2015-11-12 10:26:21,099 DEBUG : BROWSER_OUTPUT:
10:26:22 INFO - 2015-11-12 10:26:22,718 DEBUG : BROWSER_OUTPUT: Cycle 1(21): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:26:23 INFO - 2015-11-12 10:26:23,419 DEBUG : BROWSER_OUTPUT: RSS: Main: 182489088
10:26:23 INFO - 2015-11-12 10:26:23,419 DEBUG : BROWSER_OUTPUT:
10:26:24 INFO - 2015-11-12 10:26:24,985 DEBUG : BROWSER_OUTPUT: Cycle 1(22): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:26:25 INFO - 2015-11-12 10:26:25,667 DEBUG : BROWSER_OUTPUT: 1447352785660 addons.productaddons ERROR Request failed certificate checks: [Exception... "SSL is required and URI scheme is not https." nsresult: "0x8000ffff (NS_ERROR_UNEXPECTED)" location: "JS frame :: resource://gre/modules/CertUtils.jsm :: checkCert :: line 145" data: no]
10:26:25 INFO - 2015-11-12 10:26:25,703 DEBUG : BROWSER_OUTPUT: RSS: Main: 189202432
10:26:25 INFO - 2015-11-12 10:26:25,703 DEBUG : BROWSER_OUTPUT:
10:26:27 INFO - 2015-11-12 10:26:27,257 DEBUG : BROWSER_OUTPUT: Cycle 1(23): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:26:27 INFO - 2015-11-12 10:26:27,958 DEBUG : BROWSER_OUTPUT: RSS: Main: 191664128
10:26:27 INFO - 2015-11-12 10:26:27,958 DEBUG : BROWSER_OUTPUT:
10:26:29 INFO - 2015-11-12 10:26:29,524 DEBUG : BROWSER_OUTPUT: Cycle 1(24): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:26:30 INFO - 2015-11-12 10:26:30,226 DEBUG : BROWSER_OUTPUT: RSS: Main: 191782912
10:26:30 INFO - 2015-11-12 10:26:30,226 DEBUG : BROWSER_OUTPUT:
10:26:31 INFO - 2015-11-12 10:26:31,885 DEBUG : BROWSER_OUTPUT: Cycle 1(25): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:26:32 INFO - 2015-11-12 10:26:32,595 DEBUG : BROWSER_OUTPUT: RSS: Main: 195424256
10:26:32 INFO - 2015-11-12 10:26:32,595 DEBUG : BROWSER_OUTPUT:
10:26:33 INFO - 2015-11-12 10:26:33,839 DEBUG : BROWSER_OUTPUT:
10:26:33 INFO - 2015-11-12 10:26:33,839 DEBUG : BROWSER_OUTPUT: (firefox:29721): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed
10:26:33 INFO - 2015-11-12 10:26:33,860 DEBUG : BROWSER_OUTPUT: Cycle 1(1): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:26:34 INFO - 2015-11-12 10:26:34,441 DEBUG : BROWSER_OUTPUT: RSS: Main: 190300160
10:26:34 INFO - 2015-11-12 10:26:34,441 DEBUG : BROWSER_OUTPUT:
10:26:35 INFO - 2015-11-12 10:26:35,268 DEBUG : BROWSER_OUTPUT: Cycle 1(2): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:26:35 INFO - 2015-11-12 10:26:35,855 DEBUG : BROWSER_OUTPUT: RSS: Main: 187457536
10:26:35 INFO - 2015-11-12 10:26:35,855 DEBUG : BROWSER_OUTPUT:
10:26:36 INFO - 2015-11-12 10:26:36,737 DEBUG : BROWSER_OUTPUT: Cycle 1(3): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:26:37 INFO - 2015-11-12 10:26:37,326 DEBUG : BROWSER_OUTPUT: RSS: Main: 188792832
10:26:37 INFO - 2015-11-12 10:26:37,326 DEBUG : BROWSER_OUTPUT:
10:26:38 INFO - 2015-11-12 10:26:38,180 DEBUG : BROWSER_OUTPUT: Cycle 1(4): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:26:38 INFO - 2015-11-12 10:26:38,765 DEBUG : BROWSER_OUTPUT: RSS: Main: 180592640
10:26:38 INFO - 2015-11-12 10:26:38,765 DEBUG : BROWSER_OUTPUT:
10:26:39 INFO - 2015-11-12 10:26:39,619 DEBUG : BROWSER_OUTPUT: Cycle 1(5): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:26:40 INFO - 2015-11-12 10:26:40,205 DEBUG : BROWSER_OUTPUT: RSS: Main: 181293056
10:26:40 INFO - 2015-11-12 10:26:40,205 DEBUG : BROWSER_OUTPUT:
10:26:41 INFO - 2015-11-12 10:26:41,067 DEBUG : BROWSER_OUTPUT: Cycle 1(6): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:26:41 INFO - 2015-11-12 10:26:41,653 DEBUG : BROWSER_OUTPUT: RSS: Main: 178884608
10:26:41 INFO - 2015-11-12 10:26:41,653 DEBUG : BROWSER_OUTPUT:
10:26:42 INFO - 2015-11-12 10:26:42,515 DEBUG : BROWSER_OUTPUT: Cycle 1(7): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:26:43 INFO - 2015-11-12 10:26:43,101 DEBUG : BROWSER_OUTPUT: RSS: Main: 180535296
10:26:43 INFO - 2015-11-12 10:26:43,101 DEBUG : BROWSER_OUTPUT:
10:26:43 INFO - 2015-11-12 10:26:43,963 DEBUG : BROWSER_OUTPUT: Cycle 1(8): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:26:44 INFO - 2015-11-12 10:26:44,544 DEBUG : BROWSER_OUTPUT: RSS: Main: 179060736
10:26:44 INFO - 2015-11-12 10:26:44,544 DEBUG : BROWSER_OUTPUT:
10:26:45 INFO - 2015-11-12 10:26:45,411 DEBUG : BROWSER_OUTPUT: Cycle 1(9): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:26:45 INFO - 2015-11-12 10:26:45,997 DEBUG : BROWSER_OUTPUT: RSS: Main: 178196480
10:26:45 INFO - 2015-11-12 10:26:45,997 DEBUG : BROWSER_OUTPUT:
10:26:46 INFO - 2015-11-12 10:26:46,824 DEBUG : BROWSER_OUTPUT: Cycle 1(10): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:26:47 INFO - 2015-11-12 10:26:47,411 DEBUG : BROWSER_OUTPUT: RSS: Main: 180772864
10:26:47 INFO - 2015-11-12 10:26:47,411 DEBUG : BROWSER_OUTPUT:
10:26:48 INFO - 2015-11-12 10:26:48,273 DEBUG : BROWSER_OUTPUT: Cycle 1(11): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:26:48 INFO - 2015-11-12 10:26:48,858 DEBUG : BROWSER_OUTPUT: RSS: Main: 179191808
10:26:48 INFO - 2015-11-12 10:26:48,858 DEBUG : BROWSER_OUTPUT:
10:26:49 INFO - 2015-11-12 10:26:49,740 DEBUG : BROWSER_OUTPUT: Cycle 1(12): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:26:50 INFO - 2015-11-12 10:26:50,322 DEBUG : BROWSER_OUTPUT: RSS: Main: 180776960
10:26:50 INFO - 2015-11-12 10:26:50,322 DEBUG : BROWSER_OUTPUT:
10:26:51 INFO - 2015-11-12 10:26:51,184 DEBUG : BROWSER_OUTPUT: Cycle 1(13): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:26:51 INFO - 2015-11-12 10:26:51,770 DEBUG : BROWSER_OUTPUT: RSS: Main: 178880512
10:26:51 INFO - 2015-11-12 10:26:51,770 DEBUG : BROWSER_OUTPUT:
10:26:52 INFO - 2015-11-12 10:26:52,637 DEBUG : BROWSER_OUTPUT: Cycle 1(14): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:26:53 INFO - 2015-11-12 10:26:53,223 DEBUG : BROWSER_OUTPUT: RSS: Main: 178106368
10:26:53 INFO - 2015-11-12 10:26:53,223 DEBUG : BROWSER_OUTPUT:
10:26:54 INFO - 2015-11-12 10:26:54,105 DEBUG : BROWSER_OUTPUT: Cycle 1(15): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:26:54 INFO - 2015-11-12 10:26:54,706 DEBUG : BROWSER_OUTPUT: RSS: Main: 176394240
10:26:54 INFO - 2015-11-12 10:26:54,706 DEBUG : BROWSER_OUTPUT:
10:26:55 INFO - 2015-11-12 10:26:55,576 DEBUG : BROWSER_OUTPUT: Cycle 1(16): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:26:56 INFO - 2015-11-12 10:26:56,170 DEBUG : BROWSER_OUTPUT: RSS: Main: 179576832
10:26:56 INFO - 2015-11-12 10:26:56,170 DEBUG : BROWSER_OUTPUT:
10:26:57 INFO - 2015-11-12 10:26:57,032 DEBUG : BROWSER_OUTPUT: Cycle 1(17): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:26:57 INFO - 2015-11-12 10:26:57,618 DEBUG : BROWSER_OUTPUT: RSS: Main: 178106368
10:26:57 INFO - 2015-11-12 10:26:57,618 DEBUG : BROWSER_OUTPUT:
10:26:58 INFO - 2015-11-12 10:26:58,480 DEBUG : BROWSER_OUTPUT: Cycle 1(18): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:26:59 INFO - 2015-11-12 10:26:59,066 DEBUG : BROWSER_OUTPUT: RSS: Main: 178733056
10:26:59 INFO - 2015-11-12 10:26:59,066 DEBUG : BROWSER_OUTPUT:
10:26:59 INFO - 2015-11-12 10:26:59,948 DEBUG : BROWSER_OUTPUT: Cycle 1(19): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:27:00 INFO - 2015-11-12 10:27:00,542 DEBUG : BROWSER_OUTPUT: RSS: Main: 178102272
10:27:00 INFO - 2015-11-12 10:27:00,542 DEBUG : BROWSER_OUTPUT:
10:27:01 INFO - 2015-11-12 10:27:01,429 DEBUG : BROWSER_OUTPUT: Cycle 1(20): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:27:02 INFO - 2015-11-12 10:27:02,030 DEBUG : BROWSER_OUTPUT: RSS: Main: 178577408
10:27:02 INFO - 2015-11-12 10:27:02,030 DEBUG : BROWSER_OUTPUT:
10:27:02 INFO - 2015-11-12 10:27:02,913 DEBUG : BROWSER_OUTPUT: Cycle 1(21): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:27:03 INFO - 2015-11-12 10:27:03,503 DEBUG : BROWSER_OUTPUT: RSS: Main: 179130368
10:27:03 INFO - 2015-11-12 10:27:03,503 DEBUG : BROWSER_OUTPUT:
10:27:04 INFO - 2015-11-12 10:27:04,364 DEBUG : BROWSER_OUTPUT: Cycle 1(22): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:27:04 INFO - 2015-11-12 10:27:04,946 DEBUG : BROWSER_OUTPUT: RSS: Main: 179707904
10:27:04 INFO - 2015-11-12 10:27:04,946 DEBUG : BROWSER_OUTPUT:
10:27:05 INFO - 2015-11-12 10:27:05,775 DEBUG : BROWSER_OUTPUT: Cycle 1(23): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:27:06 INFO - 2015-11-12 10:27:06,361 DEBUG : BROWSER_OUTPUT: RSS: Main: 178118656
10:27:06 INFO - 2015-11-12 10:27:06,361 DEBUG : BROWSER_OUTPUT:
10:27:07 INFO - 2015-11-12 10:27:07,228 DEBUG : BROWSER_OUTPUT: Cycle 1(24): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:27:07 INFO - 2015-11-12 10:27:07,814 DEBUG : BROWSER_OUTPUT: RSS: Main: 179986432
10:27:07 INFO - 2015-11-12 10:27:07,815 DEBUG : BROWSER_OUTPUT:
10:27:08 INFO - 2015-11-12 10:27:08,696 DEBUG : BROWSER_OUTPUT: Cycle 1(25): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:27:08 INFO - 2015-11-12 10:27:08,947 DEBUG : BROWSER_OUTPUT: RSS: Main: 181645312
10:27:08 INFO - 2015-11-12 10:27:08,947 DEBUG : BROWSER_OUTPUT:
10:27:08 INFO - 2015-11-12 10:27:08,947 DEBUG : BROWSER_OUTPUT: __start_tp_report
10:27:08 INFO - 2015-11-12 10:27:08,947 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load
10:27:08 INFO - 2015-11-12 10:27:08,947 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load_details
10:27:08 INFO - 2015-11-12 10:27:08,947 DEBUG : BROWSER_OUTPUT: |i|pagename|runs|
10:27:08 INFO - 2015-11-12 10:27:08,948 DEBUG : BROWSER_OUTPUT: |0;dhtml.html;1389;1474;1476;1558;1468;1462;1468;1466;1548;1471;1563;1559;1366;1456;1491;1473;1475;1492;1476;1479;1561;1487;1471;1476;1562
10:27:08 INFO - 2015-11-12 10:27:08,948 DEBUG : BROWSER_OUTPUT: |1;tablemutation.html;333;324;327;326;327;326;326;325;326;324;327;328;325;325;328;327;327;324;326;326;328;324;325;329;328
10:27:08 INFO - 2015-11-12 10:27:08,948 DEBUG : BROWSER_OUTPUT: __end_tp_report
10:27:08 INFO - 2015-11-12 10:27:08,948 DEBUG : BROWSER_OUTPUT: __start_cc_report
10:27:08 INFO - 2015-11-12 10:27:08,948 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_cycle_collect,6831
10:27:08 INFO - 2015-11-12 10:27:08,949 DEBUG : BROWSER_OUTPUT: __end_cc_report
10:27:08 INFO - 2015-11-12 10:27:08,949 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352828944__endTimestamp
10:27:08 INFO - 2015-11-12 10:27:08,949 DEBUG : BROWSER_OUTPUT:
10:27:08 INFO - 2015-11-12 10:27:08,949 DEBUG : BROWSER_OUTPUT: ------- Summary: start -------
10:27:08 INFO - 2015-11-12 10:27:08,949 DEBUG : BROWSER_OUTPUT: Number of tests: 2
10:27:08 INFO - 2015-11-12 10:27:08,950 DEBUG : BROWSER_OUTPUT:
10:27:08 INFO - 2015-11-12 10:27:08,950 DEBUG : BROWSER_OUTPUT: [#0] dhtml.html Cycles:25 Average:1486.68 Median:1476.00 stddev:49.71 (3.4%) stddev-sans-first:46.33
10:27:08 INFO - 2015-11-12 10:27:08,951 DEBUG : BROWSER_OUTPUT: Values: 1389.0 1474.0 1476.0 1558.0 1468.0 1462.0 1468.0 1466.0 1548.0 1471.0 1563.0 1559.0 1366.0 1456.0 1491.0 1473.0 1475.0 1492.0 1476.0 1479.0 1561.0 1487.0 1471.0 1476.0 1562.0
10:27:08 INFO - 2015-11-12 10:27:08,951 DEBUG : BROWSER_OUTPUT:
10:27:08 INFO - 2015-11-12 10:27:08,951 DEBUG : BROWSER_OUTPUT: [#1] tablemutation.html Cycles:25 Average:326.44 Median:326.00 stddev:1.98 (0.6%) stddev-sans-first:1.46
10:27:08 INFO - 2015-11-12 10:27:08,951 DEBUG : BROWSER_OUTPUT: Values: 333.0 324.0 327.0 326.0 327.0 326.0 326.0 325.0 326.0 324.0 327.0 328.0 325.0 325.0 328.0 327.0 327.0 324.0 326.0 326.0 328.0 324.0 325.0 329.0 328.0
10:27:08 INFO - 2015-11-12 10:27:08,951 DEBUG : BROWSER_OUTPUT: -------- Summary: end --------
10:27:08 INFO - 2015-11-12 10:27:08,951 DEBUG : BROWSER_OUTPUT:
10:27:09 INFO - 2015-11-12 10:27:09,674 INFO : Browser exited with error code: 0
10:27:09 INFO - 2015-11-12 10:27:09,694 INFO : Completed test a11yr (00:01:53)
10:27:09 INFO - 2015-11-12 10:27:09,694 INFO : Starting test ts_paint
10:27:09 INFO - 2015-11-12 10:27:09,694 DEBUG : operating with platform_type : linux_
10:27:09 INFO - 2015-11-12 10:27:09,694 INFO : Initialising browser for ts_paint test...
10:27:09 INFO - 2015-11-12 10:27:09,700 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/getInfo.html
10:27:13 INFO - 2015-11-12 10:27:13,561 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
10:27:13 INFO - 2015-11-12 10:27:13,561 DEBUG : BROWSER_OUTPUT: colorDepth:24
10:27:13 INFO - 2015-11-12 10:27:13,561 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697
10:27:13 INFO - 2015-11-12 10:27:13,561 DEBUG : BROWSER_OUTPUT: __metrics
10:27:13 INFO - 2015-11-12 10:27:13,710 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]
10:27:15 INFO - 2015-11-12 10:27:15,019 INFO : Browser initialized.
10:27:15 INFO - 2015-11-12 10:27:15,020 INFO : Running cycle 1/20 for ts_paint test...
10:27:15 INFO - 2015-11-12 10:27:15,020 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html
10:27:16 INFO - 2015-11-12 10:27:16,660 DEBUG : BROWSER_OUTPUT: __start_report1639__end_report
10:27:16 INFO - 2015-11-12 10:27:16,660 DEBUG : BROWSER_OUTPUT:
10:27:16 INFO - 2015-11-12 10:27:16,676 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352836675__endTimestamp
10:27:17 INFO - 2015-11-12 10:27:17,558 INFO : Browser exited with error code: 0
10:27:17 INFO - 2015-11-12 10:27:17,560 INFO : Running cycle 2/20 for ts_paint test...
10:27:17 INFO - 2015-11-12 10:27:17,560 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html
10:27:18 INFO - 2015-11-12 10:27:18,690 DEBUG : BROWSER_OUTPUT: __start_report1122__end_report
10:27:18 INFO - 2015-11-12 10:27:18,690 DEBUG : BROWSER_OUTPUT:
10:27:18 INFO - 2015-11-12 10:27:18,694 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352838693__endTimestamp
10:27:19 INFO - 2015-11-12 10:27:19,449 INFO : Browser exited with error code: 0
10:27:19 INFO - 2015-11-12 10:27:19,451 INFO : Running cycle 3/20 for ts_paint test...
10:27:19 INFO - 2015-11-12 10:27:19,451 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html
10:27:20 INFO - 2015-11-12 10:27:20,642 DEBUG : BROWSER_OUTPUT: __start_report1189__end_report
10:27:20 INFO - 2015-11-12 10:27:20,642 DEBUG : BROWSER_OUTPUT:
10:27:20 INFO - 2015-11-12 10:27:20,646 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352840645__endTimestamp
10:27:21 INFO - 2015-11-12 10:27:21,438 INFO : Browser exited with error code: 0
10:27:21 INFO - 2015-11-12 10:27:21,440 INFO : Running cycle 4/20 for ts_paint test...
10:27:21 INFO - 2015-11-12 10:27:21,440 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html
10:27:22 INFO - 2015-11-12 10:27:22,560 DEBUG : BROWSER_OUTPUT: __start_report1115__end_report
10:27:22 INFO - 2015-11-12 10:27:22,560 DEBUG : BROWSER_OUTPUT:
10:27:22 INFO - 2015-11-12 10:27:22,596 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352842591__endTimestamp
10:27:23 INFO - 2015-11-12 10:27:23,426 INFO : Browser exited with error code: 0
10:27:23 INFO - 2015-11-12 10:27:23,428 INFO : Running cycle 5/20 for ts_paint test...
10:27:23 INFO - 2015-11-12 10:27:23,428 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html
10:27:24 INFO - 2015-11-12 10:27:24,576 DEBUG : BROWSER_OUTPUT: __start_report1148__end_report
10:27:24 INFO - 2015-11-12 10:27:24,577 DEBUG : BROWSER_OUTPUT:
10:27:24 INFO - 2015-11-12 10:27:24,584 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352844581__endTimestamp
10:27:25 INFO - 2015-11-12 10:27:25,414 INFO : Browser exited with error code: 0
10:27:25 INFO - 2015-11-12 10:27:25,416 INFO : Running cycle 6/20 for ts_paint test...
10:27:25 INFO - 2015-11-12 10:27:25,416 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html
10:27:26 INFO - 2015-11-12 10:27:26,529 DEBUG : BROWSER_OUTPUT: __start_report1102__end_report
10:27:26 INFO - 2015-11-12 10:27:26,529 DEBUG : BROWSER_OUTPUT:
10:27:26 INFO - 2015-11-12 10:27:26,544 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352846539__endTimestamp
10:27:27 INFO - 2015-11-12 10:27:27,403 INFO : Browser exited with error code: 0
10:27:27 INFO - 2015-11-12 10:27:27,404 INFO : Running cycle 7/20 for ts_paint test...
10:27:27 INFO - 2015-11-12 10:27:27,405 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html
10:27:28 INFO - 2015-11-12 10:27:28,559 DEBUG : BROWSER_OUTPUT: __start_report1147__end_report
10:27:28 INFO - 2015-11-12 10:27:28,560 DEBUG : BROWSER_OUTPUT:
10:27:28 INFO - 2015-11-12 10:27:28,575 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352848574__endTimestamp
10:27:29 INFO - 2015-11-12 10:27:29,441 INFO : Browser exited with error code: 0
10:27:29 INFO - 2015-11-12 10:27:29,443 INFO : Running cycle 8/20 for ts_paint test...
10:27:29 INFO - 2015-11-12 10:27:29,443 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html
10:27:30 INFO - 2015-11-12 10:27:30,599 DEBUG : BROWSER_OUTPUT: __start_report1145__end_report
10:27:30 INFO - 2015-11-12 10:27:30,599 DEBUG : BROWSER_OUTPUT:
10:27:30 INFO - 2015-11-12 10:27:30,627 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352850624__endTimestamp
10:27:31 INFO - 2015-11-12 10:27:31,532 INFO : Browser exited with error code: 0
10:27:31 INFO - 2015-11-12 10:27:31,533 INFO : Running cycle 9/20 for ts_paint test...
10:27:31 INFO - 2015-11-12 10:27:31,534 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html
10:27:32 INFO - 2015-11-12 10:27:32,680 DEBUG : BROWSER_OUTPUT: __start_report1141__end_report
10:27:32 INFO - 2015-11-12 10:27:32,680 DEBUG : BROWSER_OUTPUT:
10:27:32 INFO - 2015-11-12 10:27:32,687 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352852685__endTimestamp
10:27:33 INFO - 2015-11-12 10:27:33,571 INFO : Browser exited with error code: 0
10:27:33 INFO - 2015-11-12 10:27:33,573 INFO : Running cycle 10/20 for ts_paint test...
10:27:33 INFO - 2015-11-12 10:27:33,573 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html
10:27:34 INFO - 2015-11-12 10:27:34,710 DEBUG : BROWSER_OUTPUT: __start_report1129__end_report
10:27:34 INFO - 2015-11-12 10:27:34,710 DEBUG : BROWSER_OUTPUT:
10:27:34 INFO - 2015-11-12 10:27:34,725 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352854723__endTimestamp
10:27:35 INFO - 2015-11-12 10:27:35,559 INFO : Browser exited with error code: 0
10:27:35 INFO - 2015-11-12 10:27:35,560 INFO : Running cycle 11/20 for ts_paint test...
10:27:35 INFO - 2015-11-12 10:27:35,561 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html
10:27:36 INFO - 2015-11-12 10:27:36,717 DEBUG : BROWSER_OUTPUT: __start_report1157__end_report
10:27:36 INFO - 2015-11-12 10:27:36,717 DEBUG : BROWSER_OUTPUT:
10:27:36 INFO - 2015-11-12 10:27:36,725 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352856723__endTimestamp
10:27:37 INFO - 2015-11-12 10:27:37,548 INFO : Browser exited with error code: 0
10:27:37 INFO - 2015-11-12 10:27:37,549 INFO : Running cycle 12/20 for ts_paint test...
10:27:37 INFO - 2015-11-12 10:27:37,550 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html
10:27:38 INFO - 2015-11-12 10:27:38,723 DEBUG : BROWSER_OUTPUT: __start_report1172__end_report
10:27:38 INFO - 2015-11-12 10:27:38,724 DEBUG : BROWSER_OUTPUT:
10:27:38 INFO - 2015-11-12 10:27:38,731 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352858727__endTimestamp
10:27:39 INFO - 2015-11-12 10:27:39,685 INFO : Browser exited with error code: 0
10:27:39 INFO - 2015-11-12 10:27:39,687 INFO : Running cycle 13/20 for ts_paint test...
10:27:39 INFO - 2015-11-12 10:27:39,687 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html
10:27:40 INFO - 2015-11-12 10:27:40,823 DEBUG : BROWSER_OUTPUT: __start_report1130__end_report
10:27:40 INFO - 2015-11-12 10:27:40,824 DEBUG : BROWSER_OUTPUT:
10:27:40 INFO - 2015-11-12 10:27:40,839 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352860837__endTimestamp
10:27:41 INFO - 2015-11-12 10:27:41,676 INFO : Browser exited with error code: 0
10:27:41 INFO - 2015-11-12 10:27:41,677 INFO : Running cycle 14/20 for ts_paint test...
10:27:41 INFO - 2015-11-12 10:27:41,677 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html
10:27:42 INFO - 2015-11-12 10:27:42,832 DEBUG : BROWSER_OUTPUT: __start_report1154__end_report
10:27:42 INFO - 2015-11-12 10:27:42,832 DEBUG : BROWSER_OUTPUT:
10:27:42 INFO - 2015-11-12 10:27:42,848 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352862846__endTimestamp
10:27:43 INFO - 2015-11-12 10:27:43,715 INFO : Browser exited with error code: 0
10:27:43 INFO - 2015-11-12 10:27:43,717 INFO : Running cycle 15/20 for ts_paint test...
10:27:43 INFO - 2015-11-12 10:27:43,717 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html
10:27:44 INFO - 2015-11-12 10:27:44,866 DEBUG : BROWSER_OUTPUT: __start_report1142__end_report
10:27:44 INFO - 2015-11-12 10:27:44,866 DEBUG : BROWSER_OUTPUT:
10:27:44 INFO - 2015-11-12 10:27:44,881 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352864875__endTimestamp
10:27:45 INFO - 2015-11-12 10:27:45,754 INFO : Browser exited with error code: 0
10:27:45 INFO - 2015-11-12 10:27:45,755 INFO : Running cycle 16/20 for ts_paint test...
10:27:45 INFO - 2015-11-12 10:27:45,755 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html
10:27:46 INFO - 2015-11-12 10:27:46,876 DEBUG : BROWSER_OUTPUT: __start_report1117__end_report
10:27:46 INFO - 2015-11-12 10:27:46,876 DEBUG : BROWSER_OUTPUT:
10:27:46 INFO - 2015-11-12 10:27:46,884 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352866883__endTimestamp
10:27:47 INFO - 2015-11-12 10:27:47,745 INFO : Browser exited with error code: 0
10:27:47 INFO - 2015-11-12 10:27:47,746 INFO : Running cycle 17/20 for ts_paint test...
10:27:47 INFO - 2015-11-12 10:27:47,746 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html
10:27:48 INFO - 2015-11-12 10:27:48,877 DEBUG : BROWSER_OUTPUT: __start_report1118__end_report
10:27:48 INFO - 2015-11-12 10:27:48,878 DEBUG : BROWSER_OUTPUT:
10:27:48 INFO - 2015-11-12 10:27:48,879 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352868878__endTimestamp
10:27:49 INFO - 2015-11-12 10:27:49,821 INFO : Browser exited with error code: 0
10:27:49 INFO - 2015-11-12 10:27:49,823 INFO : Running cycle 18/20 for ts_paint test...
10:27:49 INFO - 2015-11-12 10:27:49,823 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html
10:27:50 INFO - 2015-11-12 10:27:50,945 DEBUG : BROWSER_OUTPUT: __start_report1115__end_report
10:27:50 INFO - 2015-11-12 10:27:50,945 DEBUG : BROWSER_OUTPUT:
10:27:50 INFO - 2015-11-12 10:27:50,961 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352870953__endTimestamp
10:27:51 INFO - 2015-11-12 10:27:51,861 INFO : Browser exited with error code: 0
10:27:51 INFO - 2015-11-12 10:27:51,862 INFO : Running cycle 19/20 for ts_paint test...
10:27:51 INFO - 2015-11-12 10:27:51,862 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html
10:27:53 INFO - 2015-11-12 10:27:53,013 DEBUG : BROWSER_OUTPUT: __start_report1139__end_report
10:27:53 INFO - 2015-11-12 10:27:53,013 DEBUG : BROWSER_OUTPUT:
10:27:53 INFO - 2015-11-12 10:27:53,028 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352873023__endTimestamp
10:27:53 INFO - 2015-11-12 10:27:53,900 INFO : Browser exited with error code: 0
10:27:53 INFO - 2015-11-12 10:27:53,901 INFO : Running cycle 20/20 for ts_paint test...
10:27:53 INFO - 2015-11-12 10:27:53,902 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html
10:27:55 INFO - 2015-11-12 10:27:55,018 DEBUG : BROWSER_OUTPUT: __start_report1118__end_report
10:27:55 INFO - 2015-11-12 10:27:55,018 DEBUG : BROWSER_OUTPUT:
10:27:55 INFO - 2015-11-12 10:27:55,033 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352875028__endTimestamp
10:27:55 INFO - 2015-11-12 10:27:55,940 INFO : Browser exited with error code: 0
10:27:55 INFO - 2015-11-12 10:27:55,960 INFO : Completed test ts_paint (00:00:46)
10:27:55 INFO - 2015-11-12 10:27:55,960 INFO : Starting test tpaint
10:27:55 INFO - 2015-11-12 10:27:55,960 DEBUG : operating with platform_type : linux_
10:27:55 INFO - 2015-11-12 10:27:55,960 INFO : Initialising browser for tpaint test...
10:27:55 INFO - 2015-11-12 10:27:55,966 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpxX1WRg/profile http://localhost:53596/getInfo.html
10:27:59 INFO - 2015-11-12 10:27:59,835 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
10:27:59 INFO - 2015-11-12 10:27:59,835 DEBUG : BROWSER_OUTPUT: colorDepth:24
10:27:59 INFO - 2015-11-12 10:27:59,835 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697
10:27:59 INFO - 2015-11-12 10:27:59,835 DEBUG : BROWSER_OUTPUT: __metrics
10:27:59 INFO - 2015-11-12 10:27:59,972 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]
10:28:01 INFO - 2015-11-12 10:28:01,084 INFO : Browser initialized.
10:28:01 INFO - 2015-11-12 10:28:01,085 INFO : Running cycle 1/1 for tpaint test...
10:28:01 INFO - 2015-11-12 10:28:01,085 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpxX1WRg/profile file:///builds/slave/test/build/tests/talos/talos/startup_test/tpaint.html?auto=1
10:28:27 INFO - 2015-11-12 10:28:27,252 DEBUG : BROWSER_OUTPUT: __start_report206.16499999999996|206.85000000000036|208.0550000000003|209.64000000000306|212.0049999999992|212.10000000000036|212.48500000000058|215.19999999999982|217.8099999999995|220.2449999999999|220.98000000000002|221.54500000000007|222.16999999999825|223.29500000000007|226.3050000000003|231.65999999999985|232.66500000000087|240.3100000000013|245|279.34000000000015__end_report__startTimestamp1447352907245__endTimestamp
10:28:27 INFO - 2015-11-12 10:28:27,252 DEBUG : BROWSER_OUTPUT: openingTimes=206.85000000000036,208.0550000000003,209.64000000000306,212.0049999999992,212.10000000000036,212.48500000000058,215.19999999999982,217.8099999999995,220.2449999999999,220.98000000000002,221.54500000000007,222.16999999999825,223.29500000000007,226.3050000000003,231.65999999999985,232.66500000000087,240.3100000000013,245,279.34000000000015
10:28:27 INFO - 2015-11-12 10:28:27,252 DEBUG : BROWSER_OUTPUT: avgOpenTime:223.19
10:28:27 INFO - 2015-11-12 10:28:27,252 DEBUG : BROWSER_OUTPUT: minOpenTime:206.16
10:28:27 INFO - 2015-11-12 10:28:27,252 DEBUG : BROWSER_OUTPUT: maxOpenTime:279.34
10:28:27 INFO - 2015-11-12 10:28:27,253 DEBUG : BROWSER_OUTPUT: medOpenTime:220.61249999999995
10:28:27 INFO - 2015-11-12 10:28:27,253 DEBUG : BROWSER_OUTPUT: __xulWinOpenTime:220.61249999999995
10:28:28 INFO - 2015-11-12 10:28:28,322 INFO : Browser exited with error code: 0
10:28:28 INFO - 2015-11-12 10:28:28,333 INFO : Completed test tpaint (00:00:32)
10:28:28 INFO - 2015-11-12 10:28:28,333 INFO : Starting test sessionrestore
10:28:28 INFO - 2015-11-12 10:28:28,333 DEBUG : operating with platform_type : linux_
10:28:28 INFO - 2015-11-12 10:28:28,333 INFO : Initialising browser for sessionrestore test...
10:28:28 INFO - 2015-11-12 10:28:28,342 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2w9Cmm/profile http://localhost:53596/getInfo.html
10:28:35 INFO - 2015-11-12 10:28:35,268 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
10:28:35 INFO - 2015-11-12 10:28:35,269 DEBUG : BROWSER_OUTPUT: colorDepth:24
10:28:35 INFO - 2015-11-12 10:28:35,269 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1151/811
10:28:35 INFO - 2015-11-12 10:28:35,269 DEBUG : BROWSER_OUTPUT: __metrics
10:28:35 INFO - 2015-11-12 10:28:35,417 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]
10:28:36 INFO - 2015-11-12 10:28:36,272 DEBUG : BROWSER_OUTPUT: JavaScript error: resource://gre/modules/IndexedDBHelper.jsm, line 138: UnknownError: The operation failed for reasons unrelated to the database itself and not covered by any other error code.
10:28:36 INFO - 2015-11-12 10:28:36,348 DEBUG : BROWSER_OUTPUT: console.error:
10:28:36 INFO - 2015-11-12 10:28:36,348 DEBUG : BROWSER_OUTPUT: Message: Error: Connection closed before committing the transaction.
10:28:36 INFO - 2015-11-12 10:28:36,348 DEBUG : BROWSER_OUTPUT: Stack:
10:28:36 INFO - 2015-11-12 10:28:36,349 DEBUG : BROWSER_OUTPUT: ConnectionData.prototype<.executeTransaction/promise resource://gre/modules/Promise-backend.js:934:23
10:28:36 INFO - 2015-11-12 10:28:36,349 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:813:7
10:28:36 INFO - 2015-11-12 10:28:36,349 DEBUG : BROWSER_OUTPUT: Promise*this.PromiseWalker.scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:744:11
10:28:36 INFO - 2015-11-12 10:28:36,349 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:776:7
10:28:36 INFO - 2015-11-12 10:28:36,349 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:711:7
10:28:36 INFO - 2015-11-12 10:28:36,349 DEBUG : BROWSER_OUTPUT: TaskImpl_run@resource://gre/modules/Task.jsm:319:13
10:28:36 INFO - 2015-11-12 10:28:36,349 DEBUG : BROWSER_OUTPUT: Spinner.prototype.observe@resource://gre/modules/AsyncShutdown.jsm:523:9
10:28:36 INFO - 2015-11-12 10:28:36,350 DEBUG : BROWSER_OUTPUT: nsAsyncShutdownBarrier.prototype.wait/<@resource://gre/components/nsAsyncShutdown.js:215:7
10:28:36 INFO - 2015-11-12 10:28:36,350 DEBUG : BROWSER_OUTPUT: Spinner.prototype.observe@resource://gre/modules/AsyncShutdown.jsm:523:9
10:28:36 INFO - 2015-11-12 10:28:36,350 DEBUG : BROWSER_OUTPUT:
10:28:37 INFO - 2015-11-12 10:28:37,141 INFO : Browser initialized.
10:28:37 INFO - 2015-11-12 10:28:37,142 INFO : Running cycle 1/10 for sessionrestore test...
10:28:37 INFO - 2015-11-12 10:28:37,142 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2w9Cmm/profile/sessionstore.js
10:28:37 INFO - 2015-11-12 10:28:37,144 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2w9Cmm/profile/sessionCheckpoints.json
10:28:37 INFO - 2015-11-12 10:28:37,145 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2w9Cmm/profile http://localhost:53596/startup_test/sessionrestore/index.html
10:28:41 INFO - 2015-11-12 10:28:41,948 DEBUG : BROWSER_OUTPUT: __start_report2436__end_report
10:28:41 INFO - 2015-11-12 10:28:41,949 DEBUG : BROWSER_OUTPUT:
10:28:41 INFO - 2015-11-12 10:28:41,949 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352921948__endTimestamp
10:28:41 INFO - 2015-11-12 10:28:41,949 DEBUG : BROWSER_OUTPUT:
10:28:43 INFO - 2015-11-12 10:28:43,545 INFO : Browser exited with error code: 0
10:28:43 INFO - 2015-11-12 10:28:43,547 INFO : Running cycle 2/10 for sessionrestore test...
10:28:43 INFO - 2015-11-12 10:28:43,547 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2w9Cmm/profile/sessionstore.js
10:28:43 INFO - 2015-11-12 10:28:43,549 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2w9Cmm/profile/sessionCheckpoints.json
10:28:43 INFO - 2015-11-12 10:28:43,550 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2w9Cmm/profile http://localhost:53596/startup_test/sessionrestore/index.html
10:28:47 INFO - 2015-11-12 10:28:47,795 DEBUG : BROWSER_OUTPUT: __start_report2152__end_report
10:28:47 INFO - 2015-11-12 10:28:47,795 DEBUG : BROWSER_OUTPUT:
10:28:47 INFO - 2015-11-12 10:28:47,795 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352927792__endTimestamp
10:28:47 INFO - 2015-11-12 10:28:47,795 DEBUG : BROWSER_OUTPUT:
10:28:49 INFO - 2015-11-12 10:28:49,302 INFO : Browser exited with error code: 0
10:28:49 INFO - 2015-11-12 10:28:49,303 INFO : Running cycle 3/10 for sessionrestore test...
10:28:49 INFO - 2015-11-12 10:28:49,304 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2w9Cmm/profile/sessionstore.js
10:28:49 INFO - 2015-11-12 10:28:49,305 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2w9Cmm/profile/sessionCheckpoints.json
10:28:49 INFO - 2015-11-12 10:28:49,306 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2w9Cmm/profile http://localhost:53596/startup_test/sessionrestore/index.html
10:28:53 INFO - 2015-11-12 10:28:53,605 DEBUG : BROWSER_OUTPUT: __start_report2228__end_report
10:28:53 INFO - 2015-11-12 10:28:53,605 DEBUG : BROWSER_OUTPUT:
10:28:53 INFO - 2015-11-12 10:28:53,606 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352933604__endTimestamp
10:28:53 INFO - 2015-11-12 10:28:53,606 DEBUG : BROWSER_OUTPUT:
10:28:55 INFO - 2015-11-12 10:28:55,173 INFO : Browser exited with error code: 0
10:28:55 INFO - 2015-11-12 10:28:55,175 INFO : Running cycle 4/10 for sessionrestore test...
10:28:55 INFO - 2015-11-12 10:28:55,175 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2w9Cmm/profile/sessionstore.js
10:28:55 INFO - 2015-11-12 10:28:55,177 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2w9Cmm/profile/sessionCheckpoints.json
10:28:55 INFO - 2015-11-12 10:28:55,178 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2w9Cmm/profile http://localhost:53596/startup_test/sessionrestore/index.html
10:28:59 INFO - 2015-11-12 10:28:59,495 DEBUG : BROWSER_OUTPUT: __start_report2203__end_report
10:28:59 INFO - 2015-11-12 10:28:59,495 DEBUG : BROWSER_OUTPUT:
10:28:59 INFO - 2015-11-12 10:28:59,495 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352939489__endTimestamp
10:28:59 INFO - 2015-11-12 10:28:59,495 DEBUG : BROWSER_OUTPUT:
10:29:01 INFO - 2015-11-12 10:29:01,234 INFO : Browser exited with error code: 0
10:29:01 INFO - 2015-11-12 10:29:01,235 INFO : Running cycle 5/10 for sessionrestore test...
10:29:01 INFO - 2015-11-12 10:29:01,235 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2w9Cmm/profile/sessionstore.js
10:29:01 INFO - 2015-11-12 10:29:01,237 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2w9Cmm/profile/sessionCheckpoints.json
10:29:01 INFO - 2015-11-12 10:29:01,238 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2w9Cmm/profile http://localhost:53596/startup_test/sessionrestore/index.html
10:29:05 INFO - 2015-11-12 10:29:05,591 DEBUG : BROWSER_OUTPUT: __start_report2229__end_report
10:29:05 INFO - 2015-11-12 10:29:05,591 DEBUG : BROWSER_OUTPUT:
10:29:05 INFO - 2015-11-12 10:29:05,591 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352945587__endTimestamp
10:29:05 INFO - 2015-11-12 10:29:05,591 DEBUG : BROWSER_OUTPUT:
10:29:07 INFO - 2015-11-12 10:29:07,365 INFO : Browser exited with error code: 0
10:29:07 INFO - 2015-11-12 10:29:07,367 INFO : Running cycle 6/10 for sessionrestore test...
10:29:07 INFO - 2015-11-12 10:29:07,367 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2w9Cmm/profile/sessionstore.js
10:29:07 INFO - 2015-11-12 10:29:07,369 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2w9Cmm/profile/sessionCheckpoints.json
10:29:07 INFO - 2015-11-12 10:29:07,370 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2w9Cmm/profile http://localhost:53596/startup_test/sessionrestore/index.html
10:29:11 INFO - 2015-11-12 10:29:11,655 DEBUG : BROWSER_OUTPUT: __start_report2172__end_report
10:29:11 INFO - 2015-11-12 10:29:11,655 DEBUG : BROWSER_OUTPUT:
10:29:11 INFO - 2015-11-12 10:29:11,655 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352951651__endTimestamp
10:29:11 INFO - 2015-11-12 10:29:11,655 DEBUG : BROWSER_OUTPUT:
10:29:13 INFO - 2015-11-12 10:29:13,421 INFO : Browser exited with error code: 0
10:29:13 INFO - 2015-11-12 10:29:13,423 INFO : Running cycle 7/10 for sessionrestore test...
10:29:13 INFO - 2015-11-12 10:29:13,423 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2w9Cmm/profile/sessionstore.js
10:29:13 INFO - 2015-11-12 10:29:13,425 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2w9Cmm/profile/sessionCheckpoints.json
10:29:13 INFO - 2015-11-12 10:29:13,426 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2w9Cmm/profile http://localhost:53596/startup_test/sessionrestore/index.html
10:29:17 INFO - 2015-11-12 10:29:17,730 DEBUG : BROWSER_OUTPUT: __start_report2206__end_report
10:29:17 INFO - 2015-11-12 10:29:17,730 DEBUG : BROWSER_OUTPUT:
10:29:17 INFO - 2015-11-12 10:29:17,730 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352957727__endTimestamp
10:29:17 INFO - 2015-11-12 10:29:17,730 DEBUG : BROWSER_OUTPUT:
10:29:19 INFO - 2015-11-12 10:29:19,497 INFO : Browser exited with error code: 0
10:29:19 INFO - 2015-11-12 10:29:19,499 INFO : Running cycle 8/10 for sessionrestore test...
10:29:19 INFO - 2015-11-12 10:29:19,499 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2w9Cmm/profile/sessionstore.js
10:29:19 INFO - 2015-11-12 10:29:19,501 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2w9Cmm/profile/sessionCheckpoints.json
10:29:19 INFO - 2015-11-12 10:29:19,502 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2w9Cmm/profile http://localhost:53596/startup_test/sessionrestore/index.html
10:29:23 INFO - 2015-11-12 10:29:23,768 DEBUG : BROWSER_OUTPUT: __start_report2193__end_report
10:29:23 INFO - 2015-11-12 10:29:23,768 DEBUG : BROWSER_OUTPUT:
10:29:23 INFO - 2015-11-12 10:29:23,768 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352963767__endTimestamp
10:29:23 INFO - 2015-11-12 10:29:23,768 DEBUG : BROWSER_OUTPUT:
10:29:25 INFO - 2015-11-12 10:29:25,454 INFO : Browser exited with error code: 0
10:29:25 INFO - 2015-11-12 10:29:25,455 INFO : Running cycle 9/10 for sessionrestore test...
10:29:25 INFO - 2015-11-12 10:29:25,455 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2w9Cmm/profile/sessionstore.js
10:29:25 INFO - 2015-11-12 10:29:25,458 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2w9Cmm/profile/sessionCheckpoints.json
10:29:25 INFO - 2015-11-12 10:29:25,458 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2w9Cmm/profile http://localhost:53596/startup_test/sessionrestore/index.html
10:29:29 INFO - 2015-11-12 10:29:29,753 DEBUG : BROWSER_OUTPUT: __start_report2221__end_report
10:29:29 INFO - 2015-11-12 10:29:29,753 DEBUG : BROWSER_OUTPUT:
10:29:29 INFO - 2015-11-12 10:29:29,753 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352969751__endTimestamp
10:29:29 INFO - 2015-11-12 10:29:29,753 DEBUG : BROWSER_OUTPUT:
10:29:31 INFO - 2015-11-12 10:29:31,477 INFO : Browser exited with error code: 0
10:29:31 INFO - 2015-11-12 10:29:31,479 INFO : Running cycle 10/10 for sessionrestore test...
10:29:31 INFO - 2015-11-12 10:29:31,479 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2w9Cmm/profile/sessionstore.js
10:29:31 INFO - 2015-11-12 10:29:31,481 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2w9Cmm/profile/sessionCheckpoints.json
10:29:31 INFO - 2015-11-12 10:29:31,482 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2w9Cmm/profile http://localhost:53596/startup_test/sessionrestore/index.html
10:29:35 INFO - 2015-11-12 10:29:35,781 DEBUG : BROWSER_OUTPUT: __start_report2203__end_report
10:29:35 INFO - 2015-11-12 10:29:35,782 DEBUG : BROWSER_OUTPUT:
10:29:35 INFO - 2015-11-12 10:29:35,782 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352975780__endTimestamp
10:29:35 INFO - 2015-11-12 10:29:35,782 DEBUG : BROWSER_OUTPUT:
10:29:37 INFO - 2015-11-12 10:29:37,533 INFO : Browser exited with error code: 0
10:29:37 INFO - 2015-11-12 10:29:37,549 INFO : Completed test sessionrestore (00:01:09)
10:29:37 INFO - 2015-11-12 10:29:37,549 INFO : Starting test sessionrestore_no_auto_restore
10:29:37 INFO - 2015-11-12 10:29:37,549 DEBUG : operating with platform_type : linux_
10:29:37 INFO - 2015-11-12 10:29:37,550 INFO : Initialising browser for sessionrestore_no_auto_restore test...
10:29:37 INFO - 2015-11-12 10:29:37,558 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2VaDX3/profile http://localhost:53596/getInfo.html
10:29:41 INFO - 2015-11-12 10:29:41,160 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
10:29:41 INFO - 2015-11-12 10:29:41,161 DEBUG : BROWSER_OUTPUT: colorDepth:24
10:29:41 INFO - 2015-11-12 10:29:41,161 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1151/811
10:29:41 INFO - 2015-11-12 10:29:41,161 DEBUG : BROWSER_OUTPUT: __metrics
10:29:41 INFO - 2015-11-12 10:29:41,298 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]
10:29:42 INFO - 2015-11-12 10:29:42,479 INFO : Browser initialized.
10:29:42 INFO - 2015-11-12 10:29:42,479 INFO : Running cycle 1/10 for sessionrestore_no_auto_restore test...
10:29:42 INFO - 2015-11-12 10:29:42,479 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2VaDX3/profile/sessionstore.js
10:29:42 INFO - 2015-11-12 10:29:42,482 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2VaDX3/profile/sessionCheckpoints.json
10:29:42 INFO - 2015-11-12 10:29:42,482 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2VaDX3/profile http://localhost:53596/startup_test/sessionrestore/index.html
10:29:44 INFO - 2015-11-12 10:29:44,168 DEBUG : BROWSER_OUTPUT: __start_report1077__end_report
10:29:44 INFO - 2015-11-12 10:29:44,169 DEBUG : BROWSER_OUTPUT:
10:29:44 INFO - 2015-11-12 10:29:44,169 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352984167__endTimestamp
10:29:44 INFO - 2015-11-12 10:29:44,169 DEBUG : BROWSER_OUTPUT:
10:29:45 INFO - 2015-11-12 10:29:45,193 INFO : Browser exited with error code: 0
10:29:45 INFO - 2015-11-12 10:29:45,195 INFO : Running cycle 2/10 for sessionrestore_no_auto_restore test...
10:29:45 INFO - 2015-11-12 10:29:45,195 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2VaDX3/profile/sessionstore.js
10:29:45 INFO - 2015-11-12 10:29:45,197 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2VaDX3/profile/sessionCheckpoints.json
10:29:45 INFO - 2015-11-12 10:29:45,198 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2VaDX3/profile http://localhost:53596/startup_test/sessionrestore/index.html
10:29:46 INFO - 2015-11-12 10:29:46,520 DEBUG : BROWSER_OUTPUT: __start_report814__end_report
10:29:46 INFO - 2015-11-12 10:29:46,520 DEBUG : BROWSER_OUTPUT:
10:29:46 INFO - 2015-11-12 10:29:46,520 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352986517__endTimestamp
10:29:46 INFO - 2015-11-12 10:29:46,520 DEBUG : BROWSER_OUTPUT:
10:29:47 INFO - 2015-11-12 10:29:47,421 INFO : Browser exited with error code: 0
10:29:47 INFO - 2015-11-12 10:29:47,423 INFO : Running cycle 3/10 for sessionrestore_no_auto_restore test...
10:29:47 INFO - 2015-11-12 10:29:47,423 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2VaDX3/profile/sessionstore.js
10:29:47 INFO - 2015-11-12 10:29:47,425 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2VaDX3/profile/sessionCheckpoints.json
10:29:47 INFO - 2015-11-12 10:29:47,426 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2VaDX3/profile http://localhost:53596/startup_test/sessionrestore/index.html
10:29:48 INFO - 2015-11-12 10:29:48,731 DEBUG : BROWSER_OUTPUT: __start_report822__end_report
10:29:48 INFO - 2015-11-12 10:29:48,731 DEBUG : BROWSER_OUTPUT:
10:29:48 INFO - 2015-11-12 10:29:48,731 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352988727__endTimestamp
10:29:48 INFO - 2015-11-12 10:29:48,731 DEBUG : BROWSER_OUTPUT:
10:29:49 INFO - 2015-11-12 10:29:49,741 INFO : Browser exited with error code: 0
10:29:49 INFO - 2015-11-12 10:29:49,743 INFO : Running cycle 4/10 for sessionrestore_no_auto_restore test...
10:29:49 INFO - 2015-11-12 10:29:49,743 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2VaDX3/profile/sessionstore.js
10:29:49 INFO - 2015-11-12 10:29:49,745 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2VaDX3/profile/sessionCheckpoints.json
10:29:49 INFO - 2015-11-12 10:29:49,746 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2VaDX3/profile http://localhost:53596/startup_test/sessionrestore/index.html
10:29:51 INFO - 2015-11-12 10:29:51,082 DEBUG : BROWSER_OUTPUT: __start_report839__end_report
10:29:51 INFO - 2015-11-12 10:29:51,082 DEBUG : BROWSER_OUTPUT:
10:29:51 INFO - 2015-11-12 10:29:51,082 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352991081__endTimestamp
10:29:51 INFO - 2015-11-12 10:29:51,082 DEBUG : BROWSER_OUTPUT:
10:29:52 INFO - 2015-11-12 10:29:52,105 INFO : Browser exited with error code: 0
10:29:52 INFO - 2015-11-12 10:29:52,107 INFO : Running cycle 5/10 for sessionrestore_no_auto_restore test...
10:29:52 INFO - 2015-11-12 10:29:52,107 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2VaDX3/profile/sessionstore.js
10:29:52 INFO - 2015-11-12 10:29:52,109 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2VaDX3/profile/sessionCheckpoints.json
10:29:52 INFO - 2015-11-12 10:29:52,110 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2VaDX3/profile http://localhost:53596/startup_test/sessionrestore/index.html
10:29:53 INFO - 2015-11-12 10:29:53,381 DEBUG : BROWSER_OUTPUT: __start_report802__end_report
10:29:53 INFO - 2015-11-12 10:29:53,381 DEBUG : BROWSER_OUTPUT:
10:29:53 INFO - 2015-11-12 10:29:53,381 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352993379__endTimestamp
10:29:53 INFO - 2015-11-12 10:29:53,381 DEBUG : BROWSER_OUTPUT:
10:29:54 INFO - 2015-11-12 10:29:54,365 INFO : Browser exited with error code: 0
10:29:54 INFO - 2015-11-12 10:29:54,367 INFO : Running cycle 6/10 for sessionrestore_no_auto_restore test...
10:29:54 INFO - 2015-11-12 10:29:54,367 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2VaDX3/profile/sessionstore.js
10:29:54 INFO - 2015-11-12 10:29:54,369 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2VaDX3/profile/sessionCheckpoints.json
10:29:54 INFO - 2015-11-12 10:29:54,370 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2VaDX3/profile http://localhost:53596/startup_test/sessionrestore/index.html
10:29:55 INFO - 2015-11-12 10:29:55,703 DEBUG : BROWSER_OUTPUT: __start_report798__end_report
10:29:55 INFO - 2015-11-12 10:29:55,703 DEBUG : BROWSER_OUTPUT:
10:29:55 INFO - 2015-11-12 10:29:55,703 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352995695__endTimestamp
10:29:55 INFO - 2015-11-12 10:29:55,703 DEBUG : BROWSER_OUTPUT:
10:29:56 INFO - 2015-11-12 10:29:56,765 INFO : Browser exited with error code: 0
10:29:56 INFO - 2015-11-12 10:29:56,767 INFO : Running cycle 7/10 for sessionrestore_no_auto_restore test...
10:29:56 INFO - 2015-11-12 10:29:56,767 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2VaDX3/profile/sessionstore.js
10:29:56 INFO - 2015-11-12 10:29:56,769 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2VaDX3/profile/sessionCheckpoints.json
10:29:56 INFO - 2015-11-12 10:29:56,770 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2VaDX3/profile http://localhost:53596/startup_test/sessionrestore/index.html
10:29:58 INFO - 2015-11-12 10:29:58,064 DEBUG : BROWSER_OUTPUT: __start_report775__end_report
10:29:58 INFO - 2015-11-12 10:29:58,064 DEBUG : BROWSER_OUTPUT:
10:29:58 INFO - 2015-11-12 10:29:58,064 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352998063__endTimestamp
10:29:58 INFO - 2015-11-12 10:29:58,064 DEBUG : BROWSER_OUTPUT:
10:29:59 INFO - 2015-11-12 10:29:59,121 INFO : Browser exited with error code: 0
10:29:59 INFO - 2015-11-12 10:29:59,123 INFO : Running cycle 8/10 for sessionrestore_no_auto_restore test...
10:29:59 INFO - 2015-11-12 10:29:59,123 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2VaDX3/profile/sessionstore.js
10:29:59 INFO - 2015-11-12 10:29:59,125 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2VaDX3/profile/sessionCheckpoints.json
10:29:59 INFO - 2015-11-12 10:29:59,126 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2VaDX3/profile http://localhost:53596/startup_test/sessionrestore/index.html
10:30:00 INFO - 2015-11-12 10:30:00,401 DEBUG : BROWSER_OUTPUT: __start_report757__end_report
10:30:00 INFO - 2015-11-12 10:30:00,402 DEBUG : BROWSER_OUTPUT:
10:30:00 INFO - 2015-11-12 10:30:00,402 DEBUG : BROWSER_OUTPUT: __startTimestamp1447353000401__endTimestamp
10:30:00 INFO - 2015-11-12 10:30:00,402 DEBUG : BROWSER_OUTPUT:
10:30:01 INFO - 2015-11-12 10:30:01,485 INFO : Browser exited with error code: 0
10:30:01 INFO - 2015-11-12 10:30:01,487 INFO : Running cycle 9/10 for sessionrestore_no_auto_restore test...
10:30:01 INFO - 2015-11-12 10:30:01,487 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2VaDX3/profile/sessionstore.js
10:30:01 INFO - 2015-11-12 10:30:01,489 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2VaDX3/profile/sessionCheckpoints.json
10:30:01 INFO - 2015-11-12 10:30:01,490 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2VaDX3/profile http://localhost:53596/startup_test/sessionrestore/index.html
10:30:02 INFO - 2015-11-12 10:30:02,813 DEBUG : BROWSER_OUTPUT: __start_report831__end_report
10:30:02 INFO - 2015-11-12 10:30:02,814 DEBUG : BROWSER_OUTPUT:
10:30:02 INFO - 2015-11-12 10:30:02,814 DEBUG : BROWSER_OUTPUT: __startTimestamp1447353002811__endTimestamp
10:30:02 INFO - 2015-11-12 10:30:02,814 DEBUG : BROWSER_OUTPUT:
10:30:03 INFO - 2015-11-12 10:30:03,898 INFO : Browser exited with error code: 0
10:30:03 INFO - 2015-11-12 10:30:03,899 INFO : Running cycle 10/10 for sessionrestore_no_auto_restore test...
10:30:03 INFO - 2015-11-12 10:30:03,899 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2VaDX3/profile/sessionstore.js
10:30:03 INFO - 2015-11-12 10:30:03,901 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2VaDX3/profile/sessionCheckpoints.json
10:30:03 INFO - 2015-11-12 10:30:03,902 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2VaDX3/profile http://localhost:53596/startup_test/sessionrestore/index.html
10:30:05 INFO - 2015-11-12 10:30:05,205 DEBUG : BROWSER_OUTPUT: __start_report776__end_report
10:30:05 INFO - 2015-11-12 10:30:05,205 DEBUG : BROWSER_OUTPUT:
10:30:05 INFO - 2015-11-12 10:30:05,205 DEBUG : BROWSER_OUTPUT: __startTimestamp1447353005203__endTimestamp
10:30:05 INFO - 2015-11-12 10:30:05,205 DEBUG : BROWSER_OUTPUT:
10:30:06 INFO - 2015-11-12 10:30:06,225 INFO : Browser exited with error code: 0
10:30:06 INFO - 2015-11-12 10:30:06,240 INFO : Completed test sessionrestore_no_auto_restore (00:00:28)
10:30:06 INFO - 2015-11-12 10:30:06,549 INFO : Completed test suite (00:04:50)
10:30:06 INFO - 2015-11-12 10:30:06,549 DEBUG : Working with test: a11yr
10:30:06 INFO - 2015-11-12 10:30:06,549 DEBUG : Generating results file: a11yr
10:30:06 INFO - 2015-11-12 10:30:06,550 DEBUG : Working with test: ts_paint
10:30:06 INFO - 2015-11-12 10:30:06,550 DEBUG : Generating results file: ts_paint
10:30:06 INFO - 2015-11-12 10:30:06,550 DEBUG : Working with test: tpaint
10:30:06 INFO - 2015-11-12 10:30:06,551 DEBUG : Generating results file: tpaint
10:30:06 INFO - 2015-11-12 10:30:06,551 DEBUG : Working with test: sessionrestore
10:30:06 INFO - 2015-11-12 10:30:06,551 DEBUG : Generating results file: sessionrestore
10:30:06 INFO - 2015-11-12 10:30:06,551 DEBUG : Working with test: sessionrestore_no_auto_restore
10:30:06 INFO - 2015-11-12 10:30:06,551 DEBUG : Generating results file: sessionrestore_no_auto_restore
10:30:06 INFO - 2015-11-12 10:30:06,552 INFO : Posting result 0 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
10:30:07 INFO - 2015-11-12 10:30:07,461 DEBUG : process_Request line: a11yr_paint graph.html#tests=[[223,131,35]]
10:30:07 INFO - 2015-11-12 10:30:07,461 DEBUG : process_Request line: a11yr_paint 693.97 graph.html#tests=[[223,131,35]]
10:30:07 INFO - 2015-11-12 10:30:07,461 INFO : Posting result 1 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
10:30:07 INFO - 2015-11-12 10:30:07,645 DEBUG : process_Request line: ts_paint graph.html#tests=[[83,131,35]]
10:30:07 INFO - 2015-11-12 10:30:07,645 DEBUG : process_Request line: ts_paint 1157.64 graph.html#tests=[[83,131,35]]
10:30:07 INFO - 2015-11-12 10:30:07,645 INFO : Posting result 2 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
10:30:07 INFO - 2015-11-12 10:30:07,776 DEBUG : process_Request line: tpaint graph.html#tests=[[82,131,35]]
10:30:07 INFO - 2015-11-12 10:30:07,776 DEBUG : process_Request line: tpaint 222.17 graph.html#tests=[[82,131,35]]
10:30:07 INFO - 2015-11-12 10:30:07,776 INFO : Posting result 3 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
10:30:07 INFO - 2015-11-12 10:30:07,938 DEBUG : process_Request line: sessionrestore graph.html#tests=[[313,131,35]]
10:30:07 INFO - 2015-11-12 10:30:07,939 DEBUG : process_Request line: sessionrestore 2223.12 graph.html#tests=[[313,131,35]]
10:30:07 INFO - 2015-11-12 10:30:07,939 INFO : Posting result 4 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
10:30:08 INFO - 2015-11-12 10:30:08,081 DEBUG : process_Request line: sessionrestore_no_auto_restore graph.html#tests=[[315,131,35]]
10:30:08 INFO - 2015-11-12 10:30:08,081 DEBUG : process_Request line: sessionrestore_no_auto_restore 825.19 graph.html#tests=[[315,131,35]]
10:30:08 INFO - 2015-11-12 10:30:08,082 INFO : TALOSDATA: [{"talos_counters": {}, "results": {"dhtml.html": [1389.0, 1474.0, 1476.0, 1558.0, 1468.0, 1462.0, 1468.0, 1466.0, 1548.0, 1471.0, 1563.0, 1559.0, 1366.0, 1456.0, 1491.0, 1473.0, 1475.0, 1492.0, 1476.0, 1479.0, 1561.0, 1487.0, 1471.0, 1476.0, 1562.0], "tablemutation.html": [333.0, 324.0, 327.0, 326.0, 327.0, 326.0, 326.0, 325.0, 326.0, 324.0, 327.0, 328.0, 325.0, 325.0, 328.0, 327.0, 327.0, 324.0, 326.0, 326.0, 328.0, 324.0, 325.0, 329.0, 328.0]}, "summary": {"lowerIsBetter": true, "suite": 693.9669056868825, "subtests": {"dhtml.html": {"lowerIsBetter": true, "filtered": 1476.0, "unit": "ms", "value": 1476.0}, "tablemutation.html": {"lowerIsBetter": true, "filtered": 326.0, "unit": "ms", "value": 326.0}}}, "test_machine": {"platform": "x86_64", "osversion": "Ubuntu 12.04", "os": "linux", "name": "talos-linux64-ix-048"}, "testrun": {"date": 1447352716, "suite": "a11yr", "options": {"responsiveness": false, "tpmozafterpaint": true, "tpchrome": true, "tppagecycles": 25, "tpcycles": 1, "tprender": false, "shutdown": false, "cycles": 1, "rss": false}}, "test_build": {"name": "Firefox", "version": "45.0a1", "id": "20151112100440", "branch": "Mozilla-Inbound-Non-PGO", "revision": "756632e20aa46ce0b2feebdf6f04e6dacdc09811"}}, {"talos_counters": {}, "results": {"ts_paint": [1639.0, 1122.0, 1189.0, 1115.0, 1148.0, 1102.0, 1147.0, 1145.0, 1141.0, 1129.0, 1157.0, 1172.0, 1130.0, 1154.0, 1142.0, 1117.0, 1118.0, 1115.0, 1139.0, 1118.0]}, "summary": {"suite": 1139.0, "subtests": {"ts_paint": {"filtered": 1139.0, "value": 1139.0}}}, "test_machine": {"platform": "x86_64", "osversion": "Ubuntu 12.04", "os": "linux", "name": "talos-linux64-ix-048"}, "testrun": {"date": 1447352716, "suite": "ts_paint", "options": {"responsiveness": false, "cycles": 20, "tpmozafterpaint": true, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "45.0a1", "id": "20151112100440", "branch": "Mozilla-Inbound-Non-PGO", "revision": "756632e20aa46ce0b2feebdf6f04e6dacdc09811"}}, {"talos_counters": {}, "results": {"tpaint": [206.16499999999996, 206.85000000000036, 208.0550000000003, 209.64000000000306, 212.0049999999992, 212.10000000000036, 212.48500000000058, 215.19999999999982, 217.8099999999995, 220.2449999999999, 220.98000000000002, 221.54500000000007, 222.16999999999825, 223.29500000000007, 226.3050000000003, 231.65999999999985, 232.66500000000087, 240.3100000000013, 245.0, 279.34000000000015]}, "summary": {"suite": 222.16999999999825, "subtests": {"tpaint": {"filtered": 222.16999999999825, "value": 222.16999999999825}}}, "test_machine": {"platform": "x86_64", "osversion": "Ubuntu 12.04", "os": "linux", "name": "talos-linux64-ix-048"}, "testrun": {"date": 1447352716, "suite": "tpaint", "options": {"responsiveness": false, "cycles": 1, "tpmozafterpaint": true, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "45.0a1", "id": "20151112100440", "branch": "Mozilla-Inbound-Non-PGO", "revision": "756632e20aa46ce0b2feebdf6f04e6dacdc09811"}}, {"talos_counters": {}, "results": {"sessionrestore": [2436.0, 2152.0, 2228.0, 2203.0, 2229.0, 2172.0, 2206.0, 2193.0, 2221.0, 2203.0]}, "summary": {"suite": 2203.0, "subtests": {"sessionrestore": {"filtered": 2203.0, "value": 2203.0}}}, "test_machine": {"platform": "x86_64", "osversion": "Ubuntu 12.04", "os": "linux", "name": "talos-linux64-ix-048"}, "testrun": {"date": 1447352716, "suite": "sessionrestore", "options": {"responsiveness": false, "cycles": 10, "tpmozafterpaint": false, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "45.0a1", "id": "20151112100440", "branch": "Mozilla-Inbound-Non-PGO", "revision": "756632e20aa46ce0b2feebdf6f04e6dacdc09811"}}, {"talos_counters": {}, "results": {"sessionrestore_no_auto_restore": [1077.0, 814.0, 822.0, 839.0, 802.0, 798.0, 775.0, 757.0, 831.0, 776.0]}, "summary": {"suite": 802.0, "subtests": {"sessionrestore_no_auto_restore": {"filtered": 802.0, "value": 802.0}}}, "test_machine": {"platform": "x86_64", "osversion": "Ubuntu 12.04", "os": "linux", "name": "talos-linux64-ix-048"}, "testrun": {"date": 1447352716, "suite": "sessionrestore_no_auto_restore", "options": {"responsiveness": false, "cycles": 10, "tpmozafterpaint": false, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "45.0a1", "id": "20151112100440", "branch": "Mozilla-Inbound-Non-PGO", "revision": "756632e20aa46ce0b2feebdf6f04e6dacdc09811"}}]
10:30:08 INFO - RETURN: a11yr_paint: 693.97
10:30:08 INFO - RETURN: ts_paint: 1157.64
10:30:08 INFO - RETURN: tpaint: 222.17
10:30:08 INFO - RETURN: sessionrestore: 2223.12
10:30:08 INFO - RETURN: sessionrestore_no_auto_restore: 825.19
10:30:08 INFO - TinderboxPrint: TalosResult: {"graphserver": {"sessionrestore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[313,131,35]]", "result": "2223.12"}, "a11yr_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[223,131,35]]", "result": "693.97"}, "tpaint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[82,131,35]]", "result": "222.17"}, "ts_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[83,131,35]]", "result": "1157.64"}, "sessionrestore_no_auto_restore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[315,131,35]]", "result": "825.19"}}}
10:30:08 INFO - Return code: 0
10:30:08 INFO - # TBPL SUCCESS #
10:30:08 INFO - Running post-action listener: _resource_record_post_action
10:30:08 INFO - Running post-run listener: _resource_record_post_run
10:30:09 INFO - Total resource usage - Wall time: 306s; CPU: 13.0%; Read bytes: 4096; Write bytes: 572772352; Read time: 188; Write time: 643520
10:30:09 INFO - install - Wall time: 15s; CPU: 13.0%; Read bytes: 0; Write bytes: 60739584; Read time: 0; Write time: 36948
10:30:09 INFO - run-tests - Wall time: 292s; CPU: 13.0%; Read bytes: 4096; Write bytes: 485376000; Read time: 188; Write time: 554848
10:30:09 INFO - Running post-run listener: _upload_blobber_files
10:30:09 INFO - Blob upload gear active.
10:30:09 INFO - There are no files to upload in the directory. Skipping the blob upload mechanism ...
10:30:09 INFO - Copying logs to upload dir...
10:30:09 INFO - mkdir: /builds/slave/test/build/upload/logs
program finished with exit code 0
elapsedTime=337.820912
========= master_lag: 0.02 =========
========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 5 mins, 37 secs) (at 2015-11-12 10:30:07.920176) =========
========= Started set props: build_url (results: 0, elapsed: 0 secs) (at 2015-11-12 10:30:07.925546) =========
bash -c 'for file in `ls -1`; do cat $file; done'
in dir /builds/slave/test/properties (timeout 1200 secs)
watching logfiles {}
argv: ['bash', '-c', 'for file in `ls -1`; do cat $file; done']
environment:
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/properties
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
build_url:https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2
program finished with exit code 0
elapsedTime=0.009996
build_url: 'https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2'
========= master_lag: 0.04 =========
========= Finished set props: build_url (results: 0, elapsed: 0 secs) (at 2015-11-12 10:30:07.976127) =========
========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-11-12 10:30:07.976462) =========
rm -f oauth.txt
in dir /builds/slave/test/. (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
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
program finished with exit code 0
elapsedTime=0.004612
========= master_lag: 0.05 =========
========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-11-12 10:30:08.026531) =========
========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2015-11-12 10:30:08.026857) =========
========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2015-11-12 10:30:08.027313) =========
========= Total master_lag: 0.62 =========