builder: fx-team_ubuntu64_hw_test-other-e10s
slave: talos-linux64-ix-045
starttime: 1447940253.13
results: success (0)
buildid: 20151119042020
builduid: d1c7e1fcb9d947bead57838aeca77b56
revision: bc29e2e5fac327b36b25e8d38107e09adc0a91b9
========= Started set props: master (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.133603) =========
master: http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/
========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.134080) =========
========= Started set props: basedir (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.134458) =========
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=61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
/builds/slave/test
program finished with exit code 0
elapsedTime=0.006464
basedir: '/builds/slave/test'
========= master_lag: 0.01 =========
========= Finished set props: basedir (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.155871) =========
========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.156192) =========
========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.193254) =========
========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.193522) =========
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=61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
program finished with exit code 0
elapsedTime=0.004641
========= master_lag: 0.05 =========
========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.246747) =========
========= Started set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.247017) =========
script_repo_url: https://hg.mozilla.org/build/mozharness
========= Finished set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.247363) =========
========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.247882) =========
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=61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
--2015-11-19 05:37:33-- 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% 40.3M=0s
2015-11-19 05:37:33 (40.3 MB/s) - `archiver_client.py' saved [12141/12141]
program finished with exit code 0
elapsedTime=0.189687
========= master_lag: 0.01 =========
========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.450640) =========
========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.450935) =========
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=61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
program finished with exit code 0
elapsedTime=0.014845
========= master_lag: 0.03 =========
========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.500590) =========
========= Started 'bash -c ...' (results: 0, elapsed: 1 secs) (at 2015-11-19 05:37:33.500906) =========
bash -c 'python archiver_client.py mozharness --repo integration/fx-team --rev bc29e2e5fac327b36b25e8d38107e09adc0a91b9 --destination scripts --debug'
in dir /builds/slave/test/. (timeout 1200 secs)
watching logfiles {}
argv: ['bash', '-c', u'python archiver_client.py mozharness --repo integration/fx-team --rev bc29e2e5fac327b36b25e8d38107e09adc0a91b9 --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=61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
2015-11-19 05:37:33,764 truncating revision to first 12 chars
2015-11-19 05:37:33,764 Setting DEBUG logging.
2015-11-19 05:37:33,764 attempt 1/10
2015-11-19 05:37:33,764 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/integration/fx-team/bc29e2e5fac3?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness
2015-11-19 05:37:34,869 unpacking tar archive at: fx-team-bc29e2e5fac3/testing/mozharness/
program finished with exit code 0
elapsedTime=1.389491
========= master_lag: 0.01 =========
========= Finished 'bash -c ...' (results: 0, elapsed: 1 secs) (at 2015-11-19 05:37:34.902945) =========
========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:34.903260) =========
========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:34.911946) =========
========= Started tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:34.912236) =========
TinderboxPrint: script_revlink: https://hg.mozilla.org/build/mozharness/rev/production
========= Finished tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:34.912627) =========
========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 6 mins, 17 secs) (at 2015-11-19 05:37:34.913192) =========
/tools/buildbot/bin/python scripts/scripts/talos_script.py --suite other-e10s --add-option --webServer,localhost --branch-name Fx-Team-Non-PGO --system-bits 64 --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Fx-Team-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-e10s', '--add-option', '--webServer,localhost', '--branch-name', 'Fx-Team-Non-PGO', '--system-bits', '64', '--cfg', 'talos/linux_config.py', '--download-symbols', 'ondemand', '--use-talos-json', '--blob-upload-branch', 'Fx-Team-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=61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
05:37:35 INFO - MultiFileLogger online at 20151119 05:37:35 in /builds/slave/test
05:37:35 INFO - Run as scripts/scripts/talos_script.py --suite other-e10s --add-option --webServer,localhost --branch-name Fx-Team-Non-PGO --system-bits 64 --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Fx-Team-Non-PGO
05:37:35 INFO - Dumping config to /builds/slave/test/logs/localconfig.json.
05:37:35 INFO - {'append_to_log': False,
05:37:35 INFO - 'base_work_dir': '/builds/slave/test',
05:37:35 INFO - 'blob_upload_branch': 'Fx-Team-Non-PGO',
05:37:35 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt',
05:37:35 INFO - 'branch': 'Fx-Team-Non-PGO',
05:37:35 INFO - 'buildbot_json_path': 'buildprops.json',
05:37:35 INFO - 'config_files': ('talos/linux_config.py',),
05:37:35 INFO - 'default_actions': ('clobber',
05:37:35 INFO - 'read-buildbot-config',
05:37:35 INFO - 'download-and-extract',
05:37:35 INFO - 'populate-webroot',
05:37:35 INFO - 'create-virtualenv',
05:37:35 INFO - 'install',
05:37:35 INFO - 'run-tests'),
05:37:35 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',),
05:37:35 INFO - 'download_minidump_stackwalk': True,
05:37:35 INFO - 'download_symbols': 'ondemand',
05:37:35 INFO - 'exes': {'python': '/tools/buildbot/bin/python',
05:37:35 INFO - 'tooltool.py': '/tools/tooltool.py',
05:37:35 INFO - 'virtualenv': ('/tools/buildbot/bin/python',
05:37:35 INFO - '/tools/misc-python/virtualenv.py')},
05:37:35 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub',
05:37:35 INFO - 'http://pypi.pub.build.mozilla.org/pub'),
05:37:35 INFO - 'installer_path': 'installer.exe',
05:37:35 INFO - 'log_level': 'info',
05:37:35 INFO - 'log_name': 'talos',
05:37:35 INFO - 'log_to_console': True,
05:37:35 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk',
05:37:35 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest',
05:37:35 INFO - 'opt_config_files': (),
05:37:35 INFO - 'pip_index': False,
05:37:35 INFO - 'sps_profile': False,
05:37:35 INFO - 'sps_profile_interval': 0,
05:37:35 INFO - 'suite': 'other-e10s',
05:37:35 INFO - 'system_bits': '64',
05:37:35 INFO - 'talos_extra_options': ('--webServer', 'localhost'),
05:37:35 INFO - 'title': 'talos-linux64-ix-045',
05:37:35 INFO - 'tooltool_cache': '/builds/tooltool_cache',
05:37:35 INFO - 'use_talos_json': True,
05:37:35 INFO - 'virtualenv_path': '/builds/slave/test/build/venv',
05:37:35 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None},
05:37:35 INFO - 'work_dir': 'build'}
05:37:35 INFO - #####
05:37:35 INFO - ##### Running clobber step.
05:37:35 INFO - #####
05:37:35 INFO - Running pre-action listener: _resource_record_pre_action
05:37:35 INFO - Running main action method: clobber
05:37:35 INFO - rmtree: /builds/slave/test/build
05:37:35 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1
05:37:36 INFO - Running post-action listener: _resource_record_post_action
05:37:36 INFO - #####
05:37:36 INFO - ##### Running read-buildbot-config step.
05:37:36 INFO - #####
05:37:36 INFO - Running pre-action listener: _resource_record_pre_action
05:37:36 INFO - Running main action method: read_buildbot_config
05:37:36 INFO - Using buildbot properties:
05:37:36 INFO - {
05:37:36 INFO - "properties": {
05:37:36 INFO - "buildnumber": 492,
05:37:36 INFO - "product": "firefox",
05:37:36 INFO - "script_repo_revision": "production",
05:37:36 INFO - "builddir": "fx-team_ubuntu64_hw_test-other-e10s",
05:37:36 INFO - "repository": "",
05:37:36 INFO - "buildername": "Ubuntu HW 12.04 x64 fx-team talos other-e10s",
05:37:36 INFO - "buildid": "20151119042020",
05:37:36 INFO - "slavename": "talos-linux64-ix-045",
05:37:36 INFO - "pgo_build": "False",
05:37:36 INFO - "basedir": "/builds/slave/test",
05:37:36 INFO - "project": "",
05:37:36 INFO - "platform": "ubuntu64_hw",
05:37:36 INFO - "master": "http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/",
05:37:36 INFO - "slavebuilddir": "test",
05:37:36 INFO - "scheduler": "tests-fx-team-linux64-talos",
05:37:36 INFO - "branch": "fx-team",
05:37:36 INFO - "repo_path": "integration/fx-team",
05:37:36 INFO - "stage_platform": "linux64",
05:37:36 INFO - "builduid": "d1c7e1fcb9d947bead57838aeca77b56",
05:37:36 INFO - "revision": "bc29e2e5fac327b36b25e8d38107e09adc0a91b9"
05:37:36 INFO - },
05:37:36 INFO - "sourcestamp": {
05:37:36 INFO - "repository": "",
05:37:36 INFO - "hasPatch": false,
05:37:36 INFO - "project": "",
05:37:36 INFO - "branch": "fx-team-linux64-talos",
05:37:36 INFO - "changes": [
05:37:36 INFO - {
05:37:36 INFO - "category": null,
05:37:36 INFO - "files": [
05:37:36 INFO - {
05:37:36 INFO - "url": null,
05:37:36 INFO - "name": "https://queue.taskcluster.net/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2"
05:37:36 INFO - }
05:37:36 INFO - ],
05:37:36 INFO - "repository": "",
05:37:36 INFO - "rev": "bc29e2e5fac327b36b25e8d38107e09adc0a91b9",
05:37:36 INFO - "who": "nigelbabu@gmail.com",
05:37:36 INFO - "when": 1447940203,
05:37:36 INFO - "number": 6682439,
05:37:36 INFO - "comments": "Backed out 8 changesets (bug 1171708) for bustage in it's own tests ON A CLOSED TREE\n\nBacked out changeset cae56980cbec (bug 1171708)\nBacked out changeset c60c33f9b573 (bug 1171708)\nBacked out changeset 96830bc690b6 (bug 1171708)\nBacked out changeset e1fcd236bdd3 (bug 1171708)\nBacked out changeset 9a48c1d22248 (bug 1171708)\nBacked out changeset 020345f46fbd (bug 1171708)\nBacked out changeset 6098e098d9eb (bug 1171708)\nBacked out changeset c67eefd6cf4d (bug 1171708)",
05:37:36 INFO - "project": "",
05:37:36 INFO - "at": "Thu 19 Nov 2015 05:36:43",
05:37:36 INFO - "branch": "fx-team-linux64-talos",
05:37:36 INFO - "revlink": "",
05:37:36 INFO - "properties": [
05:37:36 INFO - [
05:37:36 INFO - "buildid",
05:37:36 INFO - "20151119042020",
05:37:36 INFO - "Change"
05:37:36 INFO - ],
05:37:36 INFO - [
05:37:36 INFO - "builduid",
05:37:36 INFO - "d1c7e1fcb9d947bead57838aeca77b56",
05:37:36 INFO - "Change"
05:37:36 INFO - ],
05:37:36 INFO - [
05:37:36 INFO - "pgo_build",
05:37:36 INFO - "False",
05:37:36 INFO - "Change"
05:37:36 INFO - ]
05:37:36 INFO - ],
05:37:36 INFO - "revision": "bc29e2e5fac327b36b25e8d38107e09adc0a91b9"
05:37:36 INFO - }
05:37:36 INFO - ],
05:37:36 INFO - "revision": "bc29e2e5fac327b36b25e8d38107e09adc0a91b9"
05:37:36 INFO - }
05:37:36 INFO - }
05:37:36 INFO - Found installer url https://queue.taskcluster.net/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2.
05:37:36 INFO - Running post-action listener: _resource_record_post_action
05:37:36 INFO - #####
05:37:36 INFO - ##### Running download-and-extract step.
05:37:36 INFO - #####
05:37:36 INFO - Running pre-action listener: _resource_record_pre_action
05:37:36 INFO - Running main action method: download_and_extract
05:37:36 INFO - mkdir: /builds/slave/test/build/tests
05:37: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')]}
05:37:36 INFO - https://queue.taskcluster.net/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/test_packages.json matches https://queue.taskcluster.net
05:37:36 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/test_packages.json
05:37:36 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/test_packages.json
05:37:36 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/test_packages.json to /builds/slave/test/build/test_packages.json
05:37:36 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/test_packages.json', 'file_name': '/builds/slave/test/build/test_packages.json'}, attempt #1
05:37:43 INFO - Downloaded 1302 bytes.
05:37:43 INFO - Reading from file /builds/slave/test/build/test_packages.json
05:37:43 INFO - Using the following test package requirements:
05:37:43 INFO - {u'common': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'],
05:37:43 INFO - u'cppunittest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
05:37:43 INFO - u'firefox-45.0a1.en-US.linux-x86_64.cppunittest.tests.zip'],
05:37:43 INFO - u'jittest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
05:37:43 INFO - u'jsshell-linux-x86_64.zip'],
05:37:43 INFO - u'mochitest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
05:37:43 INFO - u'firefox-45.0a1.en-US.linux-x86_64.mochitest.tests.zip'],
05:37:43 INFO - u'mozbase': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'],
05:37:43 INFO - u'reftest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
05:37:43 INFO - u'firefox-45.0a1.en-US.linux-x86_64.reftest.tests.zip'],
05:37:43 INFO - u'talos': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
05:37:43 INFO - u'firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip'],
05:37:43 INFO - u'web-platform': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
05:37:43 INFO - u'firefox-45.0a1.en-US.linux-x86_64.web-platform.tests.zip'],
05:37:43 INFO - u'webapprt': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'],
05:37:43 INFO - u'xpcshell': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
05:37:43 INFO - u'firefox-45.0a1.en-US.linux-x86_64.xpcshell.tests.zip']}
05:37:43 INFO - Downloading packages: [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'] for test suite category: common
05:37:43 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')]}
05:37:43 INFO - https://queue.taskcluster.net/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip matches https://queue.taskcluster.net
05:37:43 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
05:37:43 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
05:37:43 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/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
05:37:43 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/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
05:37:49 INFO - Downloaded 21291001 bytes.
05:37:49 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
05:37:49 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
05:37:49 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
05:37:50 INFO - Return code: 0
05:37:50 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
05:37:50 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')]}
05:37:50 INFO - https://queue.taskcluster.net/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip matches https://queue.taskcluster.net
05:37:50 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
05:37:50 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
05:37:50 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/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
05:37:50 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/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
05:37:53 INFO - Downloaded 21291001 bytes.
05:37:53 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
05:37:53 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
05:37:53 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
05:37:54 INFO - Return code: 0
05:37: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')]}
05:37:54 INFO - https://queue.taskcluster.net/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip matches https://queue.taskcluster.net
05:37:54 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip
05:37:54 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip
05:37:54 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/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
05:37:54 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/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
05:37:55 INFO - Downloaded 11130997 bytes.
05:37:55 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
05:37:55 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip
05:37:55 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
05:37:55 INFO - Return code: 0
05:37:55 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
05:37:55 INFO - https://queue.taskcluster.net/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 matches https://queue.taskcluster.net
05:37:55 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2
05:37:55 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2
05:37:55 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/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
05:37:55 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/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
05:38:02 INFO - Downloaded 55664259 bytes.
05:38:02 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2
05:38:02 INFO - mkdir: /builds/slave/test/properties
05:38:02 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url
05:38:02 INFO - Writing to file /builds/slave/test/properties/build_url
05:38:02 INFO - Contents:
05:38:02 INFO - build_url:https://queue.taskcluster.net/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2
05:38:02 INFO - Running post-action listener: _resource_record_post_action
05:38:02 INFO - Running post-action listener: set_extra_try_arguments
05:38:02 INFO - #####
05:38:02 INFO - ##### Running populate-webroot step.
05:38:02 INFO - #####
05:38:02 INFO - Running pre-action listener: _resource_record_pre_action
05:38:02 INFO - Running main action method: populate_webroot
05:38:02 INFO - {'extra_options': {'android': ['--apkPath=%(apk_path)s']},
05:38:02 INFO - 'mobile-suites': {'remote-tp4m_nochrome': {'tests': ['tp4m']},
05:38:02 INFO - 'remote-trobocheck2': {'talos_options': ['--fennecIDs',
05:38:02 INFO - '../fennec_ids.txt'],
05:38:02 INFO - 'tests': ['tcheck2']},
05:38:02 INFO - 'remote-tsvgx': {'talos_options': ['--noChrome',
05:38:02 INFO - '--tppagecycles',
05:38:02 INFO - '7'],
05:38:02 INFO - 'tests': ['tsvgm']}},
05:38:02 INFO - 'suites': {'chromez': {'tests': ['tresize', 'tcanvasmark']},
05:38:02 INFO - 'chromez-e10s': {'talos_options': ['--e10s'],
05:38:02 INFO - 'tests': ['tresize', 'tcanvasmark']},
05:38:02 INFO - 'dromaeojs': {'tests': ['dromaeo_css', 'kraken', 'v8_7']},
05:38:02 INFO - 'dromaeojs-e10s': {'talos_options': ['--e10s'],
05:38:02 INFO - 'tests': ['dromaeo_css', 'kraken', 'v8_7']},
05:38:02 INFO - 'g1': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
05:38:02 INFO - 'tests': ['tp5o_scroll', 'glterrain']},
05:38:02 INFO - 'g1-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
05:38:02 INFO - 'talos_options': ['--e10s'],
05:38:02 INFO - 'tests': ['tp5o_scroll', 'glterrain']},
05:38:02 INFO - 'g2': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
05:38:02 INFO - 'tests': ['damp', 'tps']},
05:38:02 INFO - 'g2-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
05:38:02 INFO - 'talos_options': ['--e10s'],
05:38:02 INFO - 'tests': ['damp', 'tps']},
05:38:02 INFO - 'g3': {'tests': ['dromaeo_dom']},
05:38:02 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']},
05:38:02 INFO - 'other': {'tests': ['a11yr',
05:38:02 INFO - 'ts_paint',
05:38:02 INFO - 'tpaint',
05:38:02 INFO - 'sessionrestore',
05:38:02 INFO - 'sessionrestore_no_auto_restore']},
05:38:02 INFO - 'other-e10s': {'talos_options': ['--e10s'],
05:38:02 INFO - 'tests': ['a11yr',
05:38:02 INFO - 'ts_paint',
05:38:02 INFO - 'tpaint',
05:38:02 INFO - 'sessionrestore',
05:38:02 INFO - 'sessionrestore_no_auto_restore']},
05:38:02 INFO - 'other-e10s_l64': {'talos_options': ['--e10s'],
05:38:02 INFO - 'tests': ['a11yr',
05:38:02 INFO - 'ts_paint',
05:38:02 INFO - 'tpaint',
05:38:02 INFO - 'sessionrestore',
05:38:02 INFO - 'sessionrestore_no_auto_restore']},
05:38:02 INFO - 'other-e10s_nol64': {'talos_options': ['--e10s'],
05:38:02 INFO - 'tests': ['a11yr',
05:38:02 INFO - 'ts_paint',
05:38:02 INFO - 'tpaint',
05:38:02 INFO - 'sessionrestore',
05:38:02 INFO - 'sessionrestore_no_auto_restore']},
05:38:02 INFO - 'other_l64': {'tests': ['a11yr',
05:38:02 INFO - 'ts_paint',
05:38:02 INFO - 'tpaint',
05:38:02 INFO - 'sessionrestore',
05:38:02 INFO - 'sessionrestore_no_auto_restore']},
05:38:02 INFO - 'other_nol64': {'tests': ['a11yr',
05:38:02 INFO - 'ts_paint',
05:38:02 INFO - 'tpaint',
05:38:02 INFO - 'sessionrestore',
05:38:02 INFO - 'sessionrestore_no_auto_restore']},
05:38:02 INFO - 'svgr': {'tests': ['tsvgx',
05:38:02 INFO - 'tsvgr_opacity',
05:38:02 INFO - 'tart',
05:38:02 INFO - 'tscrollx',
05:38:02 INFO - 'cart']},
05:38:02 INFO - 'svgr-e10s': {'talos_options': ['--e10s'],
05:38:02 INFO - 'tests': ['tsvgx',
05:38:02 INFO - 'tsvgr_opacity',
05:38:02 INFO - 'tart',
05:38:02 INFO - 'tscrollx',
05:38:02 INFO - 'cart']},
05:38:02 INFO - 'tp5o': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
05:38:02 INFO - 'tests': ['tp5o']},
05:38:02 INFO - 'tp5o-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
05:38:02 INFO - 'talos_options': ['--e10s'],
05:38:02 INFO - 'tests': ['tp5o']},
05:38:02 INFO - 'xperf': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
05:38:02 INFO - 'talos_options': ['--xperf_path',
05:38:02 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'],
05:38:02 INFO - 'tests': ['tp5n']},
05:38:02 INFO - 'xperf-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
05:38:02 INFO - 'talos_options': ['--e10s',
05:38:02 INFO - '--xperf_path',
05:38:02 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'],
05:38:02 INFO - 'tests': ['tp5n']}},
05:38:02 INFO - 'talos.zip': {'path': '',
05:38:02 INFO - 'url': 'http://talos-bundles.pvt.build.mozilla.org/zips/talos.a6052c33d420.zip'}}
05:38:02 INFO - Running post-action listener: _resource_record_post_action
05:38:02 INFO - #####
05:38:02 INFO - ##### Running create-virtualenv step.
05:38:02 INFO - #####
05:38:02 INFO - Running pre-action listener: _resource_record_pre_action
05:38:02 INFO - Running main action method: create_virtualenv
05:38:02 INFO - Creating virtualenv /builds/slave/test/build/venv
05:38:02 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
05:38:02 INFO - Copy/paste: /tools/buildbot/bin/python /tools/misc-python/virtualenv.py --no-site-packages --distribute /builds/slave/test/build/venv
05:38:02 INFO - The --no-site-packages flag is deprecated; it is now the default behavior.
05:38:02 INFO - Using real prefix '/usr'
05:38:02 INFO - New python executable in /builds/slave/test/build/venv/bin/python
05:38:02 INFO - Installing distribute.............................................................................................................................................................................................done.
05:38:04 INFO - Installing pip.................done.
05:38:04 INFO - Return code: 0
05:38:04 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv
05:38:04 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
05:38:04 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
05:38:04 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
05:38:04 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
05:38:04 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
05:38:04 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
05:38:04 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'pip>=1.5']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7f165f797c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x25726c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2623900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2669b70>, '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 0x26badc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x26bb250>, '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': '61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762', '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
05:38:04 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'pip>=1.5'] in /builds/slave/test/build
05:38:04 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub pip>=1.5
05:38:04 INFO - Using env: {'DISPLAY': ':0',
05:38:04 INFO - 'HOME': '/home/cltbld',
05:38:04 INFO - 'LANG': 'en_US.UTF-8',
05:38:04 INFO - 'LANGUAGE': 'en_US:en',
05:38:04 INFO - 'LOGNAME': 'cltbld',
05:38:04 INFO - 'MAIL': '/var/mail/cltbld',
05:38:04 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
05:38:04 INFO - 'MOZ_NO_REMOTE': '1',
05:38:04 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
05:38:04 INFO - 'NO_EM_RESTART': '1',
05:38:04 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
05:38:04 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
05:38:04 INFO - 'PWD': '/builds/slave/test',
05:38:04 INFO - 'SHELL': '/bin/bash',
05:38:04 INFO - 'SHLVL': '1',
05:38:04 INFO - 'TERM': 'linux',
05:38:04 INFO - 'TMOUT': '86400',
05:38:04 INFO - 'USER': 'cltbld',
05:38:04 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762',
05:38:04 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
05:38:04 INFO - '_': '/tools/buildbot/bin/python'}
05:38:05 INFO - Ignoring indexes: https://pypi.python.org/simple/
05:38:05 INFO - Requirement already satisfied (use --upgrade to upgrade): pip>=1.5 in ./venv/lib/python2.7/site-packages/pip-1.5.5-py2.7.egg
05:38:05 INFO - Cleaning up...
05:38:05 INFO - Return code: 0
05:38:05 INFO - Installing psutil>=0.7.1 into virtualenv /builds/slave/test/build/venv
05:38:05 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
05:38:05 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
05:38:05 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
05:38:05 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
05:38:05 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
05:38:05 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
05:38:05 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'psutil>=0.7.1']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7f165f797c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x25726c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2623900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2669b70>, '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 0x26badc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x26bb250>, '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': '61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762', '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
05:38:05 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'psutil>=0.7.1'] in /builds/slave/test/build
05:38:05 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub psutil>=0.7.1
05:38:05 INFO - Using env: {'DISPLAY': ':0',
05:38:05 INFO - 'HOME': '/home/cltbld',
05:38:05 INFO - 'LANG': 'en_US.UTF-8',
05:38:05 INFO - 'LANGUAGE': 'en_US:en',
05:38:05 INFO - 'LOGNAME': 'cltbld',
05:38:05 INFO - 'MAIL': '/var/mail/cltbld',
05:38:05 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
05:38:05 INFO - 'MOZ_NO_REMOTE': '1',
05:38:05 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
05:38:05 INFO - 'NO_EM_RESTART': '1',
05:38:05 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
05:38:05 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
05:38:05 INFO - 'PWD': '/builds/slave/test',
05:38:05 INFO - 'SHELL': '/bin/bash',
05:38:05 INFO - 'SHLVL': '1',
05:38:05 INFO - 'TERM': 'linux',
05:38:05 INFO - 'TMOUT': '86400',
05:38:05 INFO - 'USER': 'cltbld',
05:38:05 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762',
05:38:05 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
05:38:05 INFO - '_': '/tools/buildbot/bin/python'}
05:38:05 INFO - Ignoring indexes: https://pypi.python.org/simple/
05:38:05 INFO - Downloading/unpacking psutil>=0.7.1
05:38:05 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available
05:38:05 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available
05:38:05 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available
05:38:05 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available
05:38:05 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available
05:38:05 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available
05:38:06 INFO - Creating supposed download cache at /builds/slave/test/build/venv/cache
05:38:06 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fpsutil-3.1.1.tar.gz
05:38:06 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/psutil/setup.py) egg_info for package psutil
05:38:07 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build'
05:38:07 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects
...
05:38:07 INFO - Installing collected packages: psutil
05:38:07 INFO - Running setup.py install for psutil
05:38:07 INFO - building 'psutil._psutil_linux' extension
05:38:07 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
05:38:07 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
05:38:07 INFO - building 'psutil._psutil_posix' extension
05:38:07 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
05:38:07 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
05:38:07 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build'
05:38:07 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ...
05:38:07 INFO - Successfully installed psutil
05:38:07 INFO - Cleaning up...
05:38:07 INFO - Return code: 0
05:38:07 INFO - Installing mozsystemmonitor==0.0.0 into virtualenv /builds/slave/test/build/venv
05:38:07 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
05:38:07 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
05:38:07 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
05:38:07 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
05:38:07 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
05:38:07 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
05:38:07 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 0x7f165f797c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x25726c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2623900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2669b70>, '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 0x26badc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x26bb250>, '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': '61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762', '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
05:38:07 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
05:38:07 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
05:38:07 INFO - Using env: {'DISPLAY': ':0',
05:38:07 INFO - 'HOME': '/home/cltbld',
05:38:07 INFO - 'LANG': 'en_US.UTF-8',
05:38:07 INFO - 'LANGUAGE': 'en_US:en',
05:38:07 INFO - 'LOGNAME': 'cltbld',
05:38:07 INFO - 'MAIL': '/var/mail/cltbld',
05:38:07 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
05:38:07 INFO - 'MOZ_NO_REMOTE': '1',
05:38:07 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
05:38:07 INFO - 'NO_EM_RESTART': '1',
05:38:07 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
05:38:07 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
05:38:07 INFO - 'PWD': '/builds/slave/test',
05:38:07 INFO - 'SHELL': '/bin/bash',
05:38:07 INFO - 'SHLVL': '1',
05:38:07 INFO - 'TERM': 'linux',
05:38:07 INFO - 'TMOUT': '86400',
05:38:07 INFO - 'USER': 'cltbld',
05:38:07 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762',
05:38:07 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
05:38:07 INFO - '_': '/tools/buildbot/bin/python'}
05:38:07 INFO - Ignoring indexes: https://pypi.python.org/simple/
05:38:07 INFO - Downloading/unpacking mozsystemmonitor==0.0.0
05:38:07 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
05:38:07 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
05:38:07 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
05:38:07 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
05:38:07 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
05:38:07 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
05:38:09 INFO - Downloading mozsystemmonitor-0.0.tar.gz
05:38:09 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fmozsystemmonitor-0.0.tar.gz
05:38:09 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/mozsystemmonitor/setup.py) egg_info for package mozsystemmonitor
05:38:09 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=0.7.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.0.0)
05:38:09 INFO - Installing collected packages: mozsystemmonitor
05:38:09 INFO - Running setup.py install for mozsystemmonitor
05:38:09 INFO - Successfully installed mozsystemmonitor
05:38:09 INFO - Cleaning up...
05:38:09 INFO - Return code: 0
05:38:09 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv
05:38:09 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')]}
05:38:09 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
05:38:09 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
05:38:09 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')]}
05:38:09 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
05:38:09 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
05:38:09 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 0x7f165f797c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x25726c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2623900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2669b70>, '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 0x26badc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x26bb250>, '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': '61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762', '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
05:38:09 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
05:38:09 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
05:38:09 INFO - Using env: {'DISPLAY': ':0',
05:38:09 INFO - 'HOME': '/home/cltbld',
05:38:09 INFO - 'LANG': 'en_US.UTF-8',
05:38:09 INFO - 'LANGUAGE': 'en_US:en',
05:38:09 INFO - 'LOGNAME': 'cltbld',
05:38:09 INFO - 'MAIL': '/var/mail/cltbld',
05:38:09 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
05:38:09 INFO - 'MOZ_NO_REMOTE': '1',
05:38:09 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
05:38:09 INFO - 'NO_EM_RESTART': '1',
05:38:09 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
05:38:09 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
05:38:09 INFO - 'PWD': '/builds/slave/test',
05:38:09 INFO - 'SHELL': '/bin/bash',
05:38:09 INFO - 'SHLVL': '1',
05:38:09 INFO - 'TERM': 'linux',
05:38:09 INFO - 'TMOUT': '86400',
05:38:09 INFO - 'USER': 'cltbld',
05:38:09 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762',
05:38:09 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
05:38:09 INFO - '_': '/tools/buildbot/bin/python'}
05:38:09 INFO - Ignoring indexes: https://pypi.python.org/simple/
05:38:09 INFO - Downloading/unpacking blobuploader==1.2.4
05:38:09 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
05:38:09 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
05:38:09 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
05:38:09 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
05:38:09 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
05:38:09 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
05:38:11 INFO - Downloading blobuploader-1.2.4.tar.gz
05:38:11 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fblobuploader-1.2.4.tar.gz
05:38:11 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blobuploader/setup.py) egg_info for package blobuploader
05:38:11 INFO - Downloading/unpacking requests==1.2.3. (from blobuploader==1.2.4)
05:38:11 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available
05:38:11 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available
05:38:11 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available
05:38:11 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available
05:38:11 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available
05:38:11 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available
05:38:11 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Frequests-1.2.3.tar.gz
05:38:11 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests
05:38:11 INFO - Downloading/unpacking docopt==0.6.1 (from blobuploader==1.2.4)
05:38:11 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available
05:38:11 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available
05:38:11 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available
05:38:11 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available
05:38:11 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available
05:38:11 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available
05:38:12 INFO - Downloading docopt-0.6.1.tar.gz
05:38:12 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fdocopt-0.6.1.tar.gz
05:38:12 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/docopt/setup.py) egg_info for package docopt
05:38:12 INFO - Installing collected packages: blobuploader, requests, docopt
05:38:12 INFO - Running setup.py install for blobuploader
05:38:12 INFO - changing mode of build/scripts-2.7/blobberc.py from 664 to 775
05:38:12 INFO - changing mode of /builds/slave/test/build/venv/bin/blobberc.py to 775
05:38:12 INFO - Running setup.py install for requests
05:38:12 INFO - Running setup.py install for docopt
05:38:12 INFO - Successfully installed blobuploader requests docopt
05:38:12 INFO - Cleaning up...
05:38:12 INFO - Return code: 0
05:38:12 INFO - Installing None into virtualenv /builds/slave/test/build/venv
05:38:12 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
05:38:12 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
05:38:12 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
05:38:12 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
05:38:12 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
05:38:12 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
05:38:12 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 0x7f165f797c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x25726c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2623900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2669b70>, '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 0x26badc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x26bb250>, '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': '61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762', '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
05:38:12 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
05:38:12 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
05:38:12 INFO - Using env: {'DISPLAY': ':0',
05:38:12 INFO - 'HOME': '/home/cltbld',
05:38:12 INFO - 'LANG': 'en_US.UTF-8',
05:38:12 INFO - 'LANGUAGE': 'en_US:en',
05:38:12 INFO - 'LOGNAME': 'cltbld',
05:38:12 INFO - 'MAIL': '/var/mail/cltbld',
05:38:12 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
05:38:12 INFO - 'MOZ_NO_REMOTE': '1',
05:38:12 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
05:38:12 INFO - 'NO_EM_RESTART': '1',
05:38:12 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
05:38:12 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
05:38:12 INFO - 'PWD': '/builds/slave/test',
05:38:12 INFO - 'SHELL': '/bin/bash',
05:38:12 INFO - 'SHLVL': '1',
05:38:12 INFO - 'TERM': 'linux',
05:38:12 INFO - 'TMOUT': '86400',
05:38:12 INFO - 'USER': 'cltbld',
05:38:12 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762',
05:38:12 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
05:38:12 INFO - '_': '/tools/buildbot/bin/python'}
05:38:12 INFO - Ignoring indexes: https://pypi.python.org/simple/
05:38:12 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser
05:38:12 INFO - Running setup.py (path:/tmp/pip-3GADbD-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser
05:38:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash
05:38:13 INFO - Running setup.py (path:/tmp/pip-uS1GeD-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash
05:38:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug
05:38:13 INFO - Running setup.py (path:/tmp/pip-VkXuuM-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug
05:38:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice
05:38:13 INFO - Running setup.py (path:/tmp/pip-kxnANZ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice
05:38:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile
05:38:13 INFO - Running setup.py (path:/tmp/pip-UpfFtk-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile
05:38:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd
05:38:13 INFO - Running setup.py (path:/tmp/pip-mfYHye-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd
05:38:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo
05:38:13 INFO - Running setup.py (path:/tmp/pip-flJk_7-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo
05:38:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall
05:38:13 INFO - Running setup.py (path:/tmp/pip-fOJvJt-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall
05:38:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak
05:38:13 INFO - Running setup.py (path:/tmp/pip-e_ZMFB-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak
05:38:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog
05:38:13 INFO - Running setup.py (path:/tmp/pip-FsadUM-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog
05:38:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork
05:38:13 INFO - Running setup.py (path:/tmp/pip-mCDMA3-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork
05:38:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess
05:38:13 INFO - Running setup.py (path:/tmp/pip-GHVHLo-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess
05:38:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile
05:38:13 INFO - Running setup.py (path:/tmp/pip-AFKWmr-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile
05:38:14 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner
05:38:14 INFO - Running setup.py (path:/tmp/pip-QJ4kdz-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner
05:38:14 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot
05:38:14 INFO - Running setup.py (path:/tmp/pip-H1MC_1-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot
05:38:14 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest
05:38:14 INFO - Running setup.py (path:/tmp/pip-_lqtQB-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest
05:38:14 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion
05:38:14 INFO - Running setup.py (path:/tmp/pip-l2gC4D-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion
05:38:14 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion
05:38:14 INFO - Running setup.py install for manifestparser
05:38:14 INFO - Installing manifestparser script to /builds/slave/test/build/venv/bin
05:38:14 INFO - Running setup.py install for mozcrash
05:38:14 INFO - Running setup.py install for mozdebug
05:38:14 INFO - Running setup.py install for mozdevice
05:38:14 INFO - Installing sutini script to /builds/slave/test/build/venv/bin
05:38:14 INFO - Installing dm script to /builds/slave/test/build/venv/bin
05:38:14 INFO - Running setup.py install for mozfile
05:38:14 INFO - Running setup.py install for mozhttpd
05:38:14 INFO - Installing mozhttpd script to /builds/slave/test/build/venv/bin
05:38:14 INFO - Running setup.py install for mozinfo
05:38:15 INFO - Installing mozinfo script to /builds/slave/test/build/venv/bin
05:38:15 INFO - Running setup.py install for mozInstall
05:38:15 INFO - Installing moz_remove_from_system script to /builds/slave/test/build/venv/bin
05:38:15 INFO - Installing mozuninstall script to /builds/slave/test/build/venv/bin
05:38:15 INFO - Installing mozinstall script to /builds/slave/test/build/venv/bin
05:38:15 INFO - Installing moz_add_to_system script to /builds/slave/test/build/venv/bin
05:38:15 INFO - Running setup.py install for mozleak
05:38:15 INFO - Running setup.py install for mozlog
05:38:15 INFO - Installing structlog script to /builds/slave/test/build/venv/bin
05:38:15 INFO - Running setup.py install for moznetwork
05:38:15 INFO - Installing moznetwork script to /builds/slave/test/build/venv/bin
05:38:15 INFO - Running setup.py install for mozprocess
05:38:15 INFO - Running setup.py install for mozprofile
05:38:15 INFO - Installing mozprofile script to /builds/slave/test/build/venv/bin
05:38:15 INFO - Installing diff-profiles script to /builds/slave/test/build/venv/bin
05:38:15 INFO - Installing view-profile script to /builds/slave/test/build/venv/bin
05:38:15 INFO - Running setup.py install for mozrunner
05:38:15 INFO - Installing mozrunner script to /builds/slave/test/build/venv/bin
05:38:15 INFO - Running setup.py install for mozscreenshot
05:38:15 INFO - Running setup.py install for moztest
05:38:15 INFO - Running setup.py install for mozversion
05:38:16 INFO - Installing mozversion script to /builds/slave/test/build/venv/bin
05:38:16 INFO - Successfully installed manifestparser mozcrash mozdebug mozdevice mozfile mozhttpd mozinfo mozInstall mozleak mozlog moznetwork mozprocess mozprofile mozrunner mozscreenshot moztest mozversion
05:38:16 INFO - Cleaning up...
05:38:16 INFO - Return code: 0
05:38:16 INFO - Installing None into virtualenv /builds/slave/test/build/venv
05:38:16 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')]}
05:38:16 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
05:38:16 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
05:38:16 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')]}
05:38:16 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
05:38:16 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
05:38:16 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 0x7f165f797c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x25726c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2623900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2669b70>, '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 0x26badc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x26bb250>, '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': '61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762', '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
05:38:16 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
05:38:16 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
05:38:16 INFO - Using env: {'DISPLAY': ':0',
05:38:16 INFO - 'HOME': '/home/cltbld',
05:38:16 INFO - 'LANG': 'en_US.UTF-8',
05:38:16 INFO - 'LANGUAGE': 'en_US:en',
05:38:16 INFO - 'LOGNAME': 'cltbld',
05:38:16 INFO - 'MAIL': '/var/mail/cltbld',
05:38:16 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
05:38:16 INFO - 'MOZ_NO_REMOTE': '1',
05:38:16 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
05:38:16 INFO - 'NO_EM_RESTART': '1',
05:38:16 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
05:38:16 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
05:38:16 INFO - 'PWD': '/builds/slave/test',
05:38:16 INFO - 'SHELL': '/bin/bash',
05:38:16 INFO - 'SHLVL': '1',
05:38:16 INFO - 'TERM': 'linux',
05:38:16 INFO - 'TMOUT': '86400',
05:38:16 INFO - 'USER': 'cltbld',
05:38:16 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762',
05:38:16 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
05:38:16 INFO - '_': '/tools/buildbot/bin/python'}
05:38:16 INFO - Ignoring indexes: https://pypi.python.org/simple/
05:38:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser
05:38:16 INFO - Running setup.py (path:/tmp/pip-2KvrK6-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser
05:38:16 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))
05:38:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash
05:38:16 INFO - Running setup.py (path:/tmp/pip-XKFC67-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash
05:38:16 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))
05:38:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug
05:38:16 INFO - Running setup.py (path:/tmp/pip-jHEq39-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug
05:38:16 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))
05:38:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice
05:38:16 INFO - Running setup.py (path:/tmp/pip-HsYUTH-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice
05:38:16 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))
05:38:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile
05:38:16 INFO - Running setup.py (path:/tmp/pip-KLBP7a-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile
05:38:16 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))
05:38:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd
05:38:16 INFO - Running setup.py (path:/tmp/pip-13kTNl-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd
05:38:16 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))
05:38:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo
05:38:16 INFO - Running setup.py (path:/tmp/pip-TzVxlU-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo
05:38:16 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))
05:38:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall
05:38:16 INFO - Running setup.py (path:/tmp/pip-uN7aKG-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall
05:38:16 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))
05:38:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak
05:38:16 INFO - Running setup.py (path:/tmp/pip-QIiyI_-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak
05:38:16 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))
05:38:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog
05:38:16 INFO - Running setup.py (path:/tmp/pip-le1kJ0-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog
05:38:17 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))
05:38:17 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork
05:38:17 INFO - Running setup.py (path:/tmp/pip-i2j2gM-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork
05:38:17 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))
05:38:17 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess
05:38:17 INFO - Running setup.py (path:/tmp/pip-ly_s4f-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess
05:38:17 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))
05:38:17 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile
05:38:17 INFO - Running setup.py (path:/tmp/pip-UB8Qnq-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile
05:38:17 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))
05:38:17 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner
05:38:17 INFO - Running setup.py (path:/tmp/pip-tiuBwx-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner
05:38:17 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))
05:38:17 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot
05:38:17 INFO - Running setup.py (path:/tmp/pip-xRn1Sr-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot
05:38:17 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))
05:38:17 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest
05:38:17 INFO - Running setup.py (path:/tmp/pip-e4PS4s-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest
05:38:17 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))
05:38:17 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion
05:38:17 INFO - Running setup.py (path:/tmp/pip-ux332L-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion
05:38:17 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))
05:38:17 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))
05:38:17 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))
05:38:17 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))
05:38:17 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))
05:38:17 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))
05:38:17 INFO - Downloading/unpacking blessings>=1.3 (from mozlog==3.0->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10))
05:38:17 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available
05:38:17 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available
05:38:17 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available
05:38:17 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available
05:38:17 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available
05:38:17 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available
05:38:19 INFO - Downloading blessings-1.5.1.tar.gz
05:38:19 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
05:38:19 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blessings/setup.py) egg_info for package blessings
05:38:19 INFO - Installing collected packages: blessings
05:38:19 INFO - Running setup.py install for blessings
05:38:19 INFO - Successfully installed blessings
05:38:19 INFO - Cleaning up...
05:38:19 INFO - Return code: 0
05:38:19 INFO - Done creating virtualenv /builds/slave/test/build/venv.
05:38:19 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze']
05:38:19 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze
05:38:19 INFO - Reading from file tmpfile_stdout
05:38:19 INFO - Current package versions:
05:38:19 INFO - argparse == 1.2.1
05:38:19 INFO - blessings == 1.5.1
05:38:19 INFO - blobuploader == 1.2.4
05:38:19 INFO - docopt == 0.6.1
05:38:19 INFO - manifestparser == 1.1
05:38:19 INFO - mozInstall == 1.12
05:38:19 INFO - mozcrash == 0.16
05:38:19 INFO - mozdebug == 0.1
05:38:19 INFO - mozdevice == 0.47
05:38:19 INFO - mozfile == 1.2
05:38:19 INFO - mozhttpd == 0.7
05:38:19 INFO - mozinfo == 0.9
05:38:19 INFO - mozleak == 0.1
05:38:19 INFO - mozlog == 3.0
05:38:19 INFO - moznetwork == 0.27
05:38:19 INFO - mozprocess == 0.22
05:38:19 INFO - mozprofile == 0.27
05:38:19 INFO - mozrunner == 6.11
05:38:19 INFO - mozscreenshot == 0.1
05:38:19 INFO - mozsystemmonitor == 0.0
05:38:19 INFO - moztest == 0.7
05:38:19 INFO - mozversion == 1.4
05:38:19 INFO - psutil == 3.1.1
05:38:19 INFO - requests == 1.2.3
05:38:19 INFO - wsgiref == 0.1.2
05:38:19 INFO - Installing None into virtualenv /builds/slave/test/build/venv
05:38:19 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')]}
05:38:19 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
05:38:19 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
05:38:19 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')]}
05:38:19 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
05:38:19 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
05:38:19 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 0x7f165f797c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x25726c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2623900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2669b70>, '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 0x26badc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x26bb250>, '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': '61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762', '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
05:38:19 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
05:38:19 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
05:38:19 INFO - Using env: {'DISPLAY': ':0',
05:38:19 INFO - 'HOME': '/home/cltbld',
05:38:19 INFO - 'LANG': 'en_US.UTF-8',
05:38:19 INFO - 'LANGUAGE': 'en_US:en',
05:38:19 INFO - 'LOGNAME': 'cltbld',
05:38:19 INFO - 'MAIL': '/var/mail/cltbld',
05:38:19 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
05:38:19 INFO - 'MOZ_NO_REMOTE': '1',
05:38:19 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
05:38:19 INFO - 'NO_EM_RESTART': '1',
05:38:19 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
05:38:19 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
05:38:19 INFO - 'PWD': '/builds/slave/test',
05:38:19 INFO - 'SHELL': '/bin/bash',
05:38:19 INFO - 'SHLVL': '1',
05:38:19 INFO - 'TERM': 'linux',
05:38:19 INFO - 'TMOUT': '86400',
05:38:19 INFO - 'USER': 'cltbld',
05:38:19 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762',
05:38:19 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
05:38:19 INFO - '_': '/tools/buildbot/bin/python'}
05:38:19 INFO - Ignoring indexes: https://pypi.python.org/simple/
05:38:19 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))
05:38:19 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))
05:38:19 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))
05:38:19 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))
05:38:19 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))
05:38:19 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))
05:38:19 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))
05:38:19 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))
05:38:19 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))
05:38:19 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))
05:38:19 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))
05:38:19 INFO - Cleaning up...
05:38:19 INFO - Return code: 0
05:38:19 INFO - Running post-action listener: _resource_record_post_action
05:38:19 INFO - Running post-action listener: _start_resource_monitoring
05:38:19 INFO - Starting resource monitoring.
05:38:19 INFO - #####
05:38:19 INFO - ##### Running install step.
05:38:19 INFO - #####
05:38:19 INFO - Running pre-action listener: _resource_record_pre_action
05:38:19 INFO - Running main action method: install
05:38:19 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze']
05:38:19 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze
05:38:20 INFO - Reading from file tmpfile_stdout
05:38:20 INFO - Detecting whether we're running mozinstall >=1.0...
05:38:20 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h']
05:38:20 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h
05:38:20 INFO - Reading from file tmpfile_stdout
05:38:20 INFO - Output received:
05:38:20 INFO - Usage: mozinstall [options] installer
05:38:20 INFO - Options:
05:38:20 INFO - -h, --help show this help message and exit
05:38:20 INFO - -d DEST, --destination=DEST
05:38:20 INFO - Directory to install application into. [default:
05:38:20 INFO - "/builds/slave/test"]
05:38:20 INFO - --app=APP Application being installed. [default: firefox]
05:38:20 INFO - mkdir: /builds/slave/test/build/application
05:38:20 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']
05:38:20 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
05:38:34 INFO - Reading from file tmpfile_stdout
05:38:34 INFO - Output received:
05:38:34 INFO - /builds/slave/test/build/application/firefox/firefox
05:38:34 INFO - Running post-action listener: _resource_record_post_action
05:38:34 INFO - #####
05:38:34 INFO - ##### Running run-tests step.
05:38:34 INFO - #####
05:38:34 INFO - Running pre-action listener: _resource_record_pre_action
05:38:34 INFO - Running main action method: run_tests
05:38:34 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version']
05:38:34 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version
05:38:34 INFO - Python 2.7.3
05:38:34 INFO - Return code: 0
05:38:34 INFO - grabbing minidump binary from tooltool
05:38:34 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
05:38:34 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 0x2669b70>, '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 0x26badc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x26bb250>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1
05:38:34 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
05:38:34 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
05:38:34 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache
05:38:34 INFO - Return code: 0
05:38:34 INFO - Chmoding /builds/slave/test/build/linux64-minidump_stackwalk to 0755
05:38:34 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir
05:38:34 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir
05:38:34 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/linux64-minidump_stackwalk
05:38:34 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir
05:38:34 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--debug', '--branchName', 'Fx-Team-Non-PGO', '--suite', 'other-e10s', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-045', '--webServer', 'localhost'] in /builds/slave/test/build
05:38:34 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/tests/talos/talos/run_tests.py --debug --branchName Fx-Team-Non-PGO --suite other-e10s --executablePath /builds/slave/test/build/application/firefox/firefox --symbolsPath https://queue.taskcluster.net/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.crashreporter-symbols.zip --title talos-linux64-ix-045 --webServer localhost
05:38:34 INFO - Using env: {'DISPLAY': ':0',
05:38:34 INFO - 'HOME': '/home/cltbld',
05:38:34 INFO - 'LANG': 'en_US.UTF-8',
05:38:34 INFO - 'LANGUAGE': 'en_US:en',
05:38:34 INFO - 'LOGNAME': 'cltbld',
05:38:34 INFO - 'MAIL': '/var/mail/cltbld',
05:38:34 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir',
05:38:34 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk',
05:38:34 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
05:38:34 INFO - 'MOZ_NO_REMOTE': '1',
05:38:34 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir',
05:38:34 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
05:38:34 INFO - 'NO_EM_RESTART': '1',
05:38:34 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
05:38:34 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
05:38:34 INFO - 'PWD': '/builds/slave/test',
05:38:34 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos',
05:38:34 INFO - 'SHELL': '/bin/bash',
05:38:34 INFO - 'SHLVL': '1',
05:38:34 INFO - 'TERM': 'linux',
05:38:34 INFO - 'TMOUT': '86400',
05:38:34 INFO - 'USER': 'cltbld',
05:38:34 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762',
05:38:34 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
05:38:34 INFO - '_': '/tools/buildbot/bin/python'}
05:38:34 INFO - Calling ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--debug', '--branchName', 'Fx-Team-Non-PGO', '--suite', 'other-e10s', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-045', '--webServer', 'localhost'] with output_timeout 3600
05:38:34 INFO - mozversion INFO | application_buildid: 20151119042020
05:38:34 INFO - mozversion INFO | application_changeset: bc29e2e5fac327b36b25e8d38107e09adc0a91b9
05:38:34 INFO - mozversion INFO | application_display_name: Nightly
05:38:34 INFO - mozversion INFO | application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384}
05:38:34 INFO - mozversion INFO | application_name: Firefox
05:38:34 INFO - mozversion INFO | application_remotingname: firefox
05:38:34 INFO - mozversion INFO | application_repository: https://hg.mozilla.org/integration/fx-team
05:38:34 INFO - mozversion INFO | application_vendor: Mozilla
05:38:34 INFO - mozversion INFO | application_version: 45.0a1
05:38:34 INFO - mozversion INFO | platform_buildid: 20151119042020
05:38:34 INFO - mozversion INFO | platform_changeset: bc29e2e5fac327b36b25e8d38107e09adc0a91b9
05:38:34 INFO - mozversion INFO | platform_repository: https://hg.mozilla.org/integration/fx-team
05:38:34 INFO - mozversion INFO | platform_version: 45.0a1
05:38:34 INFO - 2015-11-19 05:38:34,523 DEBUG : using testdate: 1447940314
05:38:34 INFO - 2015-11-19 05:38:34,523 DEBUG : actual date: 1447940314
05:38:34 INFO - 2015-11-19 05:38:34,531 INFO : starting webserver on 'localhost:59992'
05:38:34 INFO - 2015-11-19 05:38:34,532 INFO : Starting test suite talos-linux64-ix-045.e
05:38:34 INFO - 2015-11-19 05:38:34,532 INFO : Starting test a11yr
05:38:34 INFO - 2015-11-19 05:38:34,532 DEBUG : operating with platform_type : linux_
05:38:34 INFO - 2015-11-19 05:38:34,533 INFO : Initialising browser for a11yr test...
05:38:34 INFO - 2015-11-19 05:38:34,545 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_gMzSk/profile http://localhost:59992/getInfo.html
05:38:39 INFO - 2015-11-19 05:38:39,206 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
05:38:39 INFO - 2015-11-19 05:38:39,207 DEBUG : BROWSER_OUTPUT: colorDepth:24
05:38:39 INFO - 2015-11-19 05:38:39,207 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697
05:38:39 INFO - 2015-11-19 05:38:39,207 DEBUG : BROWSER_OUTPUT: __metrics
05:38:40 INFO - 2015-11-19 05:38:40,325 INFO : Browser initialized.
05:38:40 INFO - 2015-11-19 05:38:40,326 INFO : Running cycle 1/1 for a11yr test...
05:38:40 INFO - 2015-11-19 05:38:40,326 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_gMzSk/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/a11y/a11y.manifest.develop -tpchrome -tpmozafterpaint -tpnoisy -tpcycles 1 -tppagecycles 25
05:38:52 INFO - 2015-11-19 05:38:52,344 DEBUG : BROWSER_OUTPUT: RSS: Main: 141918208
05:38:52 INFO - 2015-11-19 05:38:52,345 DEBUG : BROWSER_OUTPUT:
05:38:53 INFO - 2015-11-19 05:38:53,633 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)
05:38:53 INFO - 2015-11-19 05:38:53,770 DEBUG : BROWSER_OUTPUT:
05:38:53 INFO - 2015-11-19 05:38:53,770 DEBUG : BROWSER_OUTPUT: (firefox:4447): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed
05:38:53 INFO - 2015-11-19 05:38:53,770 DEBUG : BROWSER_OUTPUT:
05:38:53 INFO - 2015-11-19 05:38:53,770 DEBUG : BROWSER_OUTPUT: (firefox:4447): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed
05:38:53 INFO - 2015-11-19 05:38:53,826 DEBUG : BROWSER_OUTPUT:
05:38:53 INFO - 2015-11-19 05:38:53,826 DEBUG : BROWSER_OUTPUT: (firefox:4447): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed
05:38:54 INFO - 2015-11-19 05:38:54,267 DEBUG : BROWSER_OUTPUT: RSS: Main: 147214336
05:38:54 INFO - 2015-11-19 05:38:54,267 DEBUG : BROWSER_OUTPUT:
05:38:55 INFO - 2015-11-19 05:38:55,659 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)
05:38:56 INFO - 2015-11-19 05:38:56,361 DEBUG : BROWSER_OUTPUT: RSS: Main: 146321408
05:38:56 INFO - 2015-11-19 05:38:56,361 DEBUG : BROWSER_OUTPUT:
05:38:57 INFO - 2015-11-19 05:38:57,746 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)
05:38:58 INFO - 2015-11-19 05:38:58,447 DEBUG : BROWSER_OUTPUT: RSS: Main: 146010112
05:38:58 INFO - 2015-11-19 05:38:58,447 DEBUG : BROWSER_OUTPUT:
05:38:59 INFO - 2015-11-19 05:38:59,873 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)
05:39:00 INFO - 2015-11-19 05:39:00,626 DEBUG : BROWSER_OUTPUT: RSS: Main: 145678336
05:39:00 INFO - 2015-11-19 05:39:00,626 DEBUG : BROWSER_OUTPUT:
05:39:02 INFO - 2015-11-19 05:39:02,012 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)
05:39:02 INFO - 2015-11-19 05:39:02,774 DEBUG : BROWSER_OUTPUT: RSS: Main: 142524416
05:39:02 INFO - 2015-11-19 05:39:02,774 DEBUG : BROWSER_OUTPUT:
05:39:04 INFO - 2015-11-19 05:39:04,150 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)
05:39:04 INFO - 2015-11-19 05:39:04,852 DEBUG : BROWSER_OUTPUT: RSS: Main: 143552512
05:39:04 INFO - 2015-11-19 05:39:04,853 DEBUG : BROWSER_OUTPUT:
05:39:06 INFO - 2015-11-19 05:39:06,270 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)
05:39:07 INFO - 2015-11-19 05:39:07,024 DEBUG : BROWSER_OUTPUT: RSS: Main: 142475264
05:39:07 INFO - 2015-11-19 05:39:07,024 DEBUG : BROWSER_OUTPUT:
05:39:08 INFO - 2015-11-19 05:39:08,436 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)
05:39:09 INFO - 2015-11-19 05:39:09,138 DEBUG : BROWSER_OUTPUT: RSS: Main: 143634432
05:39:09 INFO - 2015-11-19 05:39:09,138 DEBUG : BROWSER_OUTPUT:
05:39:10 INFO - 2015-11-19 05:39:10,717 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)
05:39:11 INFO - 2015-11-19 05:39:11,423 DEBUG : BROWSER_OUTPUT: RSS: Main: 143343616
05:39:11 INFO - 2015-11-19 05:39:11,424 DEBUG : BROWSER_OUTPUT:
05:39:13 INFO - 2015-11-19 05:39:13,001 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)
05:39:13 INFO - 2015-11-19 05:39:13,704 DEBUG : BROWSER_OUTPUT: RSS: Main: 143278080
05:39:13 INFO - 2015-11-19 05:39:13,704 DEBUG : BROWSER_OUTPUT:
05:39:15 INFO - 2015-11-19 05:39:15,073 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)
05:39:15 INFO - 2015-11-19 05:39:15,780 DEBUG : BROWSER_OUTPUT: RSS: Main: 143466496
05:39:15 INFO - 2015-11-19 05:39:15,780 DEBUG : BROWSER_OUTPUT:
05:39:17 INFO - 2015-11-19 05:39:17,176 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)
05:39:17 INFO - 2015-11-19 05:39:17,883 DEBUG : BROWSER_OUTPUT: RSS: Main: 143765504
05:39:17 INFO - 2015-11-19 05:39:17,883 DEBUG : BROWSER_OUTPUT:
05:39:19 INFO - 2015-11-19 05:39:19,482 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)
05:39:20 INFO - 2015-11-19 05:39:20,184 DEBUG : BROWSER_OUTPUT: RSS: Main: 143319040
05:39:20 INFO - 2015-11-19 05:39:20,184 DEBUG : BROWSER_OUTPUT:
05:39:21 INFO - 2015-11-19 05:39:21,595 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)
05:39:22 INFO - 2015-11-19 05:39:22,362 DEBUG : BROWSER_OUTPUT: RSS: Main: 143818752
05:39:22 INFO - 2015-11-19 05:39:22,362 DEBUG : BROWSER_OUTPUT:
05:39:23 INFO - 2015-11-19 05:39:23,977 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)
05:39:24 INFO - 2015-11-19 05:39:24,684 DEBUG : BROWSER_OUTPUT: RSS: Main: 143175680
05:39:24 INFO - 2015-11-19 05:39:24,684 DEBUG : BROWSER_OUTPUT:
05:39:26 INFO - 2015-11-19 05:39:26,061 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)
05:39:26 INFO - 2015-11-19 05:39:26,763 DEBUG : BROWSER_OUTPUT: RSS: Main: 143273984
05:39:26 INFO - 2015-11-19 05:39:26,763 DEBUG : BROWSER_OUTPUT:
05:39:28 INFO - 2015-11-19 05:39:28,156 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)
05:39:28 INFO - 2015-11-19 05:39:28,863 DEBUG : BROWSER_OUTPUT: RSS: Main: 143183872
05:39:28 INFO - 2015-11-19 05:39:28,863 DEBUG : BROWSER_OUTPUT:
05:39:30 INFO - 2015-11-19 05:39:30,268 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)
05:39:30 INFO - 2015-11-19 05:39:30,962 DEBUG : BROWSER_OUTPUT: RSS: Main: 141996032
05:39:30 INFO - 2015-11-19 05:39:30,962 DEBUG : BROWSER_OUTPUT:
05:39:32 INFO - 2015-11-19 05:39:32,392 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)
05:39:33 INFO - 2015-11-19 05:39:33,094 DEBUG : BROWSER_OUTPUT: RSS: Main: 142860288
05:39:33 INFO - 2015-11-19 05:39:33,094 DEBUG : BROWSER_OUTPUT:
05:39:34 INFO - 2015-11-19 05:39:34,483 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)
05:39:35 INFO - 2015-11-19 05:39:35,191 DEBUG : BROWSER_OUTPUT: RSS: Main: 142868480
05:39:35 INFO - 2015-11-19 05:39:35,191 DEBUG : BROWSER_OUTPUT:
05:39:36 INFO - 2015-11-19 05:39:36,575 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)
05:39:37 INFO - 2015-11-19 05:39:37,277 DEBUG : BROWSER_OUTPUT: RSS: Main: 143155200
05:39:37 INFO - 2015-11-19 05:39:37,277 DEBUG : BROWSER_OUTPUT:
05:39:38 INFO - 2015-11-19 05:39:38,682 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)
05:39:39 INFO - 2015-11-19 05:39:39,397 DEBUG : BROWSER_OUTPUT: RSS: Main: 143560704
05:39:39 INFO - 2015-11-19 05:39:39,397 DEBUG : BROWSER_OUTPUT:
05:39:40 INFO - 2015-11-19 05:39:40,802 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)
05:39:41 INFO - 2015-11-19 05:39:41,511 DEBUG : BROWSER_OUTPUT: RSS: Main: 150597632
05:39:41 INFO - 2015-11-19 05:39:41,511 DEBUG : BROWSER_OUTPUT:
05:39:41 INFO - 2015-11-19 05:39:41,990 DEBUG : BROWSER_OUTPUT: 1447940381983 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]
05:39:42 INFO - 2015-11-19 05:39:42,937 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)
05:39:43 INFO - 2015-11-19 05:39:43,658 DEBUG : BROWSER_OUTPUT: RSS: Main: 158507008
05:39:43 INFO - 2015-11-19 05:39:43,659 DEBUG : BROWSER_OUTPUT:
05:39:45 INFO - 2015-11-19 05:39:45,043 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)
05:39:45 INFO - 2015-11-19 05:39:45,757 DEBUG : BROWSER_OUTPUT: RSS: Main: 157929472
05:39:45 INFO - 2015-11-19 05:39:45,757 DEBUG : BROWSER_OUTPUT:
05:39:46 INFO - 2015-11-19 05:39:46,140 DEBUG : BROWSER_OUTPUT:
05:39:46 INFO - 2015-11-19 05:39:46,140 DEBUG : BROWSER_OUTPUT: (firefox:4447): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed
05:39:46 INFO - 2015-11-19 05:39:46,719 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)
05:39:47 INFO - 2015-11-19 05:39:47,309 DEBUG : BROWSER_OUTPUT: RSS: Main: 152285184
05:39:47 INFO - 2015-11-19 05:39:47,309 DEBUG : BROWSER_OUTPUT:
05:39:48 INFO - 2015-11-19 05:39:48,243 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)
05:39:48 INFO - 2015-11-19 05:39:48,845 DEBUG : BROWSER_OUTPUT: RSS: Main: 152743936
05:39:48 INFO - 2015-11-19 05:39:48,845 DEBUG : BROWSER_OUTPUT:
05:39:49 INFO - 2015-11-19 05:39:49,766 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)
05:39:50 INFO - 2015-11-19 05:39:50,367 DEBUG : BROWSER_OUTPUT: RSS: Main: 151793664
05:39:50 INFO - 2015-11-19 05:39:50,367 DEBUG : BROWSER_OUTPUT:
05:39:51 INFO - 2015-11-19 05:39:51,322 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)
05:39:51 INFO - 2015-11-19 05:39:51,928 DEBUG : BROWSER_OUTPUT: RSS: Main: 150601728
05:39:51 INFO - 2015-11-19 05:39:51,928 DEBUG : BROWSER_OUTPUT:
05:39:52 INFO - 2015-11-19 05:39:52,891 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)
05:39:53 INFO - 2015-11-19 05:39:53,484 DEBUG : BROWSER_OUTPUT: RSS: Main: 144220160
05:39:53 INFO - 2015-11-19 05:39:53,484 DEBUG : BROWSER_OUTPUT:
05:39:54 INFO - 2015-11-19 05:39:54,431 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)
05:39:55 INFO - 2015-11-19 05:39:55,032 DEBUG : BROWSER_OUTPUT: RSS: Main: 143130624
05:39:55 INFO - 2015-11-19 05:39:55,032 DEBUG : BROWSER_OUTPUT:
05:39:55 INFO - 2015-11-19 05:39:55,946 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)
05:39:56 INFO - 2015-11-19 05:39:56,548 DEBUG : BROWSER_OUTPUT: RSS: Main: 141570048
05:39:56 INFO - 2015-11-19 05:39:56,548 DEBUG : BROWSER_OUTPUT:
05:39:57 INFO - 2015-11-19 05:39:57,494 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)
05:39:58 INFO - 2015-11-19 05:39:58,095 DEBUG : BROWSER_OUTPUT: RSS: Main: 141824000
05:39:58 INFO - 2015-11-19 05:39:58,095 DEBUG : BROWSER_OUTPUT:
05:39:59 INFO - 2015-11-19 05:39:59,005 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)
05:39:59 INFO - 2015-11-19 05:39:59,607 DEBUG : BROWSER_OUTPUT: RSS: Main: 141479936
05:39:59 INFO - 2015-11-19 05:39:59,607 DEBUG : BROWSER_OUTPUT:
05:40:00 INFO - 2015-11-19 05:40:00,549 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)
05:40:01 INFO - 2015-11-19 05:40:01,155 DEBUG : BROWSER_OUTPUT: RSS: Main: 141811712
05:40:01 INFO - 2015-11-19 05:40:01,155 DEBUG : BROWSER_OUTPUT:
05:40:02 INFO - 2015-11-19 05:40:02,089 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)
05:40:02 INFO - 2015-11-19 05:40:02,691 DEBUG : BROWSER_OUTPUT: RSS: Main: 141414400
05:40:02 INFO - 2015-11-19 05:40:02,691 DEBUG : BROWSER_OUTPUT:
05:40:03 INFO - 2015-11-19 05:40:03,634 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)
05:40:04 INFO - 2015-11-19 05:40:04,240 DEBUG : BROWSER_OUTPUT: RSS: Main: 141668352
05:40:04 INFO - 2015-11-19 05:40:04,240 DEBUG : BROWSER_OUTPUT:
05:40:05 INFO - 2015-11-19 05:40:05,174 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)
05:40:05 INFO - 2015-11-19 05:40:05,775 DEBUG : BROWSER_OUTPUT: RSS: Main: 141602816
05:40:05 INFO - 2015-11-19 05:40:05,776 DEBUG : BROWSER_OUTPUT:
05:40:06 INFO - 2015-11-19 05:40:06,682 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)
05:40:07 INFO - 2015-11-19 05:40:07,285 DEBUG : BROWSER_OUTPUT: RSS: Main: 141770752
05:40:07 INFO - 2015-11-19 05:40:07,286 DEBUG : BROWSER_OUTPUT:
05:40:08 INFO - 2015-11-19 05:40:08,208 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)
05:40:08 INFO - 2015-11-19 05:40:08,810 DEBUG : BROWSER_OUTPUT: RSS: Main: 141742080
05:40:08 INFO - 2015-11-19 05:40:08,810 DEBUG : BROWSER_OUTPUT:
05:40:09 INFO - 2015-11-19 05:40:09,764 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)
05:40:10 INFO - 2015-11-19 05:40:10,370 DEBUG : BROWSER_OUTPUT: RSS: Main: 141688832
05:40:10 INFO - 2015-11-19 05:40:10,370 DEBUG : BROWSER_OUTPUT:
05:40:11 INFO - 2015-11-19 05:40:11,297 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)
05:40:11 INFO - 2015-11-19 05:40:11,898 DEBUG : BROWSER_OUTPUT: RSS: Main: 141647872
05:40:11 INFO - 2015-11-19 05:40:11,898 DEBUG : BROWSER_OUTPUT:
05:40:12 INFO - 2015-11-19 05:40:12,840 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)
05:40:13 INFO - 2015-11-19 05:40:13,442 DEBUG : BROWSER_OUTPUT: RSS: Main: 142970880
05:40:13 INFO - 2015-11-19 05:40:13,442 DEBUG : BROWSER_OUTPUT:
05:40:14 INFO - 2015-11-19 05:40:14,405 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)
05:40:15 INFO - 2015-11-19 05:40:15,011 DEBUG : BROWSER_OUTPUT: RSS: Main: 141160448
05:40:15 INFO - 2015-11-19 05:40:15,011 DEBUG : BROWSER_OUTPUT:
05:40:15 INFO - 2015-11-19 05:40:15,933 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)
05:40:16 INFO - 2015-11-19 05:40:16,534 DEBUG : BROWSER_OUTPUT: RSS: Main: 142901248
05:40:16 INFO - 2015-11-19 05:40:16,534 DEBUG : BROWSER_OUTPUT:
05:40:17 INFO - 2015-11-19 05:40:17,456 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)
05:40:18 INFO - 2015-11-19 05:40:18,057 DEBUG : BROWSER_OUTPUT: RSS: Main: 141115392
05:40:18 INFO - 2015-11-19 05:40:18,057 DEBUG : BROWSER_OUTPUT:
05:40:18 INFO - 2015-11-19 05:40:18,979 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)
05:40:19 INFO - 2015-11-19 05:40:19,572 DEBUG : BROWSER_OUTPUT: RSS: Main: 142802944
05:40:19 INFO - 2015-11-19 05:40:19,573 DEBUG : BROWSER_OUTPUT:
05:40:20 INFO - 2015-11-19 05:40:20,493 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)
05:40:21 INFO - 2015-11-19 05:40:21,094 DEBUG : BROWSER_OUTPUT: RSS: Main: 143052800
05:40:21 INFO - 2015-11-19 05:40:21,095 DEBUG : BROWSER_OUTPUT:
05:40:22 INFO - 2015-11-19 05:40:22,029 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)
05:40:22 INFO - 2015-11-19 05:40:22,630 DEBUG : BROWSER_OUTPUT: RSS: Main: 142974976
05:40:22 INFO - 2015-11-19 05:40:22,631 DEBUG : BROWSER_OUTPUT:
05:40:23 INFO - 2015-11-19 05:40:23,557 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)
05:40:23 INFO - 2015-11-19 05:40:23,807 DEBUG : BROWSER_OUTPUT: RSS: Main: 142757888
05:40:23 INFO - 2015-11-19 05:40:23,808 DEBUG : BROWSER_OUTPUT:
05:40:23 INFO - 2015-11-19 05:40:23,808 DEBUG : BROWSER_OUTPUT: __start_tp_report
05:40:23 INFO - 2015-11-19 05:40:23,808 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load
05:40:23 INFO - 2015-11-19 05:40:23,808 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load_details
05:40:23 INFO - 2015-11-19 05:40:23,809 DEBUG : BROWSER_OUTPUT: |i|pagename|runs|
05:40:23 INFO - 2015-11-19 05:40:23,809 DEBUG : BROWSER_OUTPUT: |0;dhtml.html;1261;1299;1307;1341;1328;1323;1344;1330;1524;1525;1315;1325;1526;1334;1527;1322;1316;1313;1348;1324;1331;1329;1333;1339;1320
05:40:23 INFO - 2015-11-19 05:40:23,809 DEBUG : BROWSER_OUTPUT: |1;tablemutation.html;380;381;377;383;390;388;378;390;378;392;387;385;399;377;388;393;393;387;402;384;380;379;387;397;386
05:40:23 INFO - 2015-11-19 05:40:23,809 DEBUG : BROWSER_OUTPUT: __end_tp_report
05:40:23 INFO - 2015-11-19 05:40:23,809 DEBUG : BROWSER_OUTPUT: __start_cc_report
05:40:23 INFO - 2015-11-19 05:40:23,809 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_cycle_collect,2755
05:40:23 INFO - 2015-11-19 05:40:23,810 DEBUG : BROWSER_OUTPUT: __end_cc_report
05:40:23 INFO - 2015-11-19 05:40:23,811 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940423807__endTimestamp
05:40:23 INFO - 2015-11-19 05:40:23,811 DEBUG : BROWSER_OUTPUT:
05:40:23 INFO - 2015-11-19 05:40:23,811 DEBUG : BROWSER_OUTPUT: ------- Summary: start -------
05:40:23 INFO - 2015-11-19 05:40:23,811 DEBUG : BROWSER_OUTPUT: Number of tests: 2
05:40:23 INFO - 2015-11-19 05:40:23,812 DEBUG : BROWSER_OUTPUT:
05:40:23 INFO - 2015-11-19 05:40:23,812 DEBUG : BROWSER_OUTPUT: [#0] dhtml.html Cycles:25 Average:1355.36 Median:1329.00 stddev:77.67 (5.8%) stddev-sans-first:76.76
05:40:23 INFO - 2015-11-19 05:40:23,812 DEBUG : BROWSER_OUTPUT: Values: 1261.0 1299.0 1307.0 1341.0 1328.0 1323.0 1344.0 1330.0 1524.0 1525.0 1315.0 1325.0 1526.0 1334.0 1527.0 1322.0 1316.0 1313.0 1348.0 1324.0 1331.0 1329.0 1333.0 1339.0 1320.0
05:40:23 INFO - 2015-11-19 05:40:23,812 DEBUG : BROWSER_OUTPUT:
05:40:23 INFO - 2015-11-19 05:40:23,812 DEBUG : BROWSER_OUTPUT: [#1] tablemutation.html Cycles:25 Average:386.44 Median:387.00 stddev:6.98 (1.8%) stddev-sans-first:6.99
05:40:23 INFO - 2015-11-19 05:40:23,812 DEBUG : BROWSER_OUTPUT: Values: 380.0 381.0 377.0 383.0 390.0 388.0 378.0 390.0 378.0 392.0 387.0 385.0 399.0 377.0 388.0 393.0 393.0 387.0 402.0 384.0 380.0 379.0 387.0 397.0 386.0
05:40:23 INFO - 2015-11-19 05:40:23,812 DEBUG : BROWSER_OUTPUT: -------- Summary: end --------
05:40:23 INFO - 2015-11-19 05:40:23,813 DEBUG : BROWSER_OUTPUT:
05:40:24 INFO - 2015-11-19 05:40:24,537 INFO : Browser exited with error code: 0
05:40:24 INFO - 2015-11-19 05:40:24,551 INFO : Completed test a11yr (00:01:50)
05:40:24 INFO - 2015-11-19 05:40:24,551 INFO : Starting test ts_paint
05:40:24 INFO - 2015-11-19 05:40:24,551 DEBUG : operating with platform_type : linux_
05:40:24 INFO - 2015-11-19 05:40:24,551 INFO : Initialising browser for ts_paint test...
05:40:24 INFO - 2015-11-19 05:40:24,557 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/getInfo.html
05:40:29 INFO - 2015-11-19 05:40:29,054 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
05:40:29 INFO - 2015-11-19 05:40:29,055 DEBUG : BROWSER_OUTPUT: colorDepth:24
05:40:29 INFO - 2015-11-19 05:40:29,055 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697
05:40:29 INFO - 2015-11-19 05:40:29,055 DEBUG : BROWSER_OUTPUT: __metrics
05:40:30 INFO - 2015-11-19 05:40:30,189 INFO : Browser initialized.
05:40:30 INFO - 2015-11-19 05:40:30,190 INFO : Running cycle 1/20 for ts_paint test...
05:40:30 INFO - 2015-11-19 05:40:30,190 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html
05:40:32 INFO - 2015-11-19 05:40:32,309 DEBUG : BROWSER_OUTPUT: __start_report480__end_report
05:40:32 INFO - 2015-11-19 05:40:32,309 DEBUG : BROWSER_OUTPUT:
05:40:32 INFO - 2015-11-19 05:40:32,317 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940432313__endTimestamp
05:40:33 INFO - 2015-11-19 05:40:33,273 INFO : Browser exited with error code: 0
05:40:33 INFO - 2015-11-19 05:40:33,275 INFO : Running cycle 2/20 for ts_paint test...
05:40:33 INFO - 2015-11-19 05:40:33,275 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html
05:40:34 INFO - 2015-11-19 05:40:34,921 DEBUG : BROWSER_OUTPUT: __start_report571__end_report
05:40:34 INFO - 2015-11-19 05:40:34,921 DEBUG : BROWSER_OUTPUT:
05:40:34 INFO - 2015-11-19 05:40:34,937 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940434931__endTimestamp
05:40:35 INFO - 2015-11-19 05:40:35,877 INFO : Browser exited with error code: 0
05:40:35 INFO - 2015-11-19 05:40:35,879 INFO : Running cycle 3/20 for ts_paint test...
05:40:35 INFO - 2015-11-19 05:40:35,879 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html
05:40:37 INFO - 2015-11-19 05:40:37,525 DEBUG : BROWSER_OUTPUT: __start_report511__end_report
05:40:37 INFO - 2015-11-19 05:40:37,525 DEBUG : BROWSER_OUTPUT:
05:40:37 INFO - 2015-11-19 05:40:37,529 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940437528__endTimestamp
05:40:38 INFO - 2015-11-19 05:40:38,478 INFO : Browser exited with error code: 0
05:40:38 INFO - 2015-11-19 05:40:38,480 INFO : Running cycle 4/20 for ts_paint test...
05:40:38 INFO - 2015-11-19 05:40:38,480 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html
05:40:40 INFO - 2015-11-19 05:40:40,133 DEBUG : BROWSER_OUTPUT: __start_report523__end_report
05:40:40 INFO - 2015-11-19 05:40:40,133 DEBUG : BROWSER_OUTPUT:
05:40:40 INFO - 2015-11-19 05:40:40,141 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940440137__endTimestamp
05:40:41 INFO - 2015-11-19 05:40:41,153 INFO : Browser exited with error code: 0
05:40:41 INFO - 2015-11-19 05:40:41,155 INFO : Running cycle 5/20 for ts_paint test...
05:40:41 INFO - 2015-11-19 05:40:41,155 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html
05:40:42 INFO - 2015-11-19 05:40:42,788 DEBUG : BROWSER_OUTPUT: __start_report519__end_report
05:40:42 INFO - 2015-11-19 05:40:42,788 DEBUG : BROWSER_OUTPUT:
05:40:42 INFO - 2015-11-19 05:40:42,804 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940442798__endTimestamp
05:40:43 INFO - 2015-11-19 05:40:43,837 INFO : Browser exited with error code: 0
05:40:43 INFO - 2015-11-19 05:40:43,839 INFO : Running cycle 6/20 for ts_paint test...
05:40:43 INFO - 2015-11-19 05:40:43,839 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html
05:40:45 INFO - 2015-11-19 05:40:45,461 DEBUG : BROWSER_OUTPUT: __start_report520__end_report
05:40:45 INFO - 2015-11-19 05:40:45,462 DEBUG : BROWSER_OUTPUT:
05:40:45 INFO - 2015-11-19 05:40:45,478 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940445471__endTimestamp
05:40:46 INFO - 2015-11-19 05:40:46,525 INFO : Browser exited with error code: 0
05:40:46 INFO - 2015-11-19 05:40:46,527 INFO : Running cycle 7/20 for ts_paint test...
05:40:46 INFO - 2015-11-19 05:40:46,527 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html
05:40:48 INFO - 2015-11-19 05:40:48,167 DEBUG : BROWSER_OUTPUT: __start_report523__end_report
05:40:48 INFO - 2015-11-19 05:40:48,167 DEBUG : BROWSER_OUTPUT:
05:40:48 INFO - 2015-11-19 05:40:48,169 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940448168__endTimestamp
05:40:49 INFO - 2015-11-19 05:40:49,237 INFO : Browser exited with error code: 0
05:40:49 INFO - 2015-11-19 05:40:49,239 INFO : Running cycle 8/20 for ts_paint test...
05:40:49 INFO - 2015-11-19 05:40:49,239 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html
05:40:50 INFO - 2015-11-19 05:40:50,914 DEBUG : BROWSER_OUTPUT: __start_report554__end_report
05:40:50 INFO - 2015-11-19 05:40:50,914 DEBUG : BROWSER_OUTPUT:
05:40:50 INFO - 2015-11-19 05:40:50,930 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940450922__endTimestamp
05:40:51 INFO - 2015-11-19 05:40:51,981 INFO : Browser exited with error code: 0
05:40:51 INFO - 2015-11-19 05:40:51,983 INFO : Running cycle 9/20 for ts_paint test...
05:40:51 INFO - 2015-11-19 05:40:51,983 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html
05:40:53 INFO - 2015-11-19 05:40:53,569 DEBUG : BROWSER_OUTPUT: __start_report504__end_report
05:40:53 INFO - 2015-11-19 05:40:53,570 DEBUG : BROWSER_OUTPUT:
05:40:53 INFO - 2015-11-19 05:40:53,585 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940453581__endTimestamp
05:40:54 INFO - 2015-11-19 05:40:54,641 INFO : Browser exited with error code: 0
05:40:54 INFO - 2015-11-19 05:40:54,643 INFO : Running cycle 10/20 for ts_paint test...
05:40:54 INFO - 2015-11-19 05:40:54,643 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html
05:40:56 INFO - 2015-11-19 05:40:56,358 DEBUG : BROWSER_OUTPUT: __start_report618__end_report
05:40:56 INFO - 2015-11-19 05:40:56,358 DEBUG : BROWSER_OUTPUT:
05:40:56 INFO - 2015-11-19 05:40:56,366 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940456362__endTimestamp
05:40:57 INFO - 2015-11-19 05:40:57,397 INFO : Browser exited with error code: 0
05:40:57 INFO - 2015-11-19 05:40:57,399 INFO : Running cycle 11/20 for ts_paint test...
05:40:57 INFO - 2015-11-19 05:40:57,399 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html
05:40:59 INFO - 2015-11-19 05:40:59,025 DEBUG : BROWSER_OUTPUT: __start_report520__end_report
05:40:59 INFO - 2015-11-19 05:40:59,025 DEBUG : BROWSER_OUTPUT:
05:40:59 INFO - 2015-11-19 05:40:59,041 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940459033__endTimestamp
05:41:00 INFO - 2015-11-19 05:41:00,057 INFO : Browser exited with error code: 0
05:41:00 INFO - 2015-11-19 05:41:00,059 INFO : Running cycle 12/20 for ts_paint test...
05:41:00 INFO - 2015-11-19 05:41:00,059 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html
05:41:01 INFO - 2015-11-19 05:41:01,701 DEBUG : BROWSER_OUTPUT: __start_report554__end_report
05:41:01 INFO - 2015-11-19 05:41:01,701 DEBUG : BROWSER_OUTPUT:
05:41:01 INFO - 2015-11-19 05:41:01,717 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940461712__endTimestamp
05:41:02 INFO - 2015-11-19 05:41:02,805 INFO : Browser exited with error code: 0
05:41:02 INFO - 2015-11-19 05:41:02,807 INFO : Running cycle 13/20 for ts_paint test...
05:41:02 INFO - 2015-11-19 05:41:02,807 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html
05:41:04 INFO - 2015-11-19 05:41:04,467 DEBUG : BROWSER_OUTPUT: __start_report549__end_report
05:41:04 INFO - 2015-11-19 05:41:04,467 DEBUG : BROWSER_OUTPUT:
05:41:04 INFO - 2015-11-19 05:41:04,483 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940464476__endTimestamp
05:41:05 INFO - 2015-11-19 05:41:05,605 INFO : Browser exited with error code: 0
05:41:05 INFO - 2015-11-19 05:41:05,607 INFO : Running cycle 14/20 for ts_paint test...
05:41:05 INFO - 2015-11-19 05:41:05,607 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html
05:41:07 INFO - 2015-11-19 05:41:07,224 DEBUG : BROWSER_OUTPUT: __start_report517__end_report
05:41:07 INFO - 2015-11-19 05:41:07,225 DEBUG : BROWSER_OUTPUT:
05:41:07 INFO - 2015-11-19 05:41:07,232 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940467230__endTimestamp
05:41:08 INFO - 2015-11-19 05:41:08,329 INFO : Browser exited with error code: 0
05:41:08 INFO - 2015-11-19 05:41:08,331 INFO : Running cycle 15/20 for ts_paint test...
05:41:08 INFO - 2015-11-19 05:41:08,331 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html
05:41:09 INFO - 2015-11-19 05:41:09,970 DEBUG : BROWSER_OUTPUT: __start_report541__end_report
05:41:09 INFO - 2015-11-19 05:41:09,970 DEBUG : BROWSER_OUTPUT:
05:41:09 INFO - 2015-11-19 05:41:09,978 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940469977__endTimestamp
05:41:11 INFO - 2015-11-19 05:41:11,021 INFO : Browser exited with error code: 0
05:41:11 INFO - 2015-11-19 05:41:11,023 INFO : Running cycle 16/20 for ts_paint test...
05:41:11 INFO - 2015-11-19 05:41:11,023 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html
05:41:12 INFO - 2015-11-19 05:41:12,656 DEBUG : BROWSER_OUTPUT: __start_report503__end_report
05:41:12 INFO - 2015-11-19 05:41:12,656 DEBUG : BROWSER_OUTPUT:
05:41:12 INFO - 2015-11-19 05:41:12,663 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940472663__endTimestamp
05:41:13 INFO - 2015-11-19 05:41:13,749 INFO : Browser exited with error code: 0
05:41:13 INFO - 2015-11-19 05:41:13,751 INFO : Running cycle 17/20 for ts_paint test...
05:41:13 INFO - 2015-11-19 05:41:13,751 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html
05:41:15 INFO - 2015-11-19 05:41:15,390 DEBUG : BROWSER_OUTPUT: __start_report534__end_report
05:41:15 INFO - 2015-11-19 05:41:15,390 DEBUG : BROWSER_OUTPUT:
05:41:15 INFO - 2015-11-19 05:41:15,406 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940475399__endTimestamp
05:41:16 INFO - 2015-11-19 05:41:16,481 INFO : Browser exited with error code: 0
05:41:16 INFO - 2015-11-19 05:41:16,483 INFO : Running cycle 18/20 for ts_paint test...
05:41:16 INFO - 2015-11-19 05:41:16,483 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html
05:41:18 INFO - 2015-11-19 05:41:18,161 DEBUG : BROWSER_OUTPUT: __start_report562__end_report
05:41:18 INFO - 2015-11-19 05:41:18,161 DEBUG : BROWSER_OUTPUT:
05:41:18 INFO - 2015-11-19 05:41:18,177 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940478170__endTimestamp
05:41:19 INFO - 2015-11-19 05:41:19,261 INFO : Browser exited with error code: 0
05:41:19 INFO - 2015-11-19 05:41:19,263 INFO : Running cycle 19/20 for ts_paint test...
05:41:19 INFO - 2015-11-19 05:41:19,263 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html
05:41:20 INFO - 2015-11-19 05:41:20,928 DEBUG : BROWSER_OUTPUT: __start_report513__end_report
05:41:20 INFO - 2015-11-19 05:41:20,928 DEBUG : BROWSER_OUTPUT:
05:41:20 INFO - 2015-11-19 05:41:20,944 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940480936__endTimestamp
05:41:22 INFO - 2015-11-19 05:41:22,025 INFO : Browser exited with error code: 0
05:41:22 INFO - 2015-11-19 05:41:22,027 INFO : Running cycle 20/20 for ts_paint test...
05:41:22 INFO - 2015-11-19 05:41:22,027 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html
05:41:23 INFO - 2015-11-19 05:41:23,708 DEBUG : BROWSER_OUTPUT: __start_report556__end_report
05:41:23 INFO - 2015-11-19 05:41:23,708 DEBUG : BROWSER_OUTPUT:
05:41:23 INFO - 2015-11-19 05:41:23,724 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940483718__endTimestamp
05:41:24 INFO - 2015-11-19 05:41:24,849 INFO : Browser exited with error code: 0
05:41:24 INFO - 2015-11-19 05:41:24,871 INFO : Completed test ts_paint (00:01:00)
05:41:24 INFO - 2015-11-19 05:41:24,871 INFO : Starting test tpaint
05:41:24 INFO - 2015-11-19 05:41:24,871 DEBUG : operating with platform_type : linux_
05:41:24 INFO - 2015-11-19 05:41:24,871 INFO : Initialising browser for tpaint test...
05:41:24 INFO - 2015-11-19 05:41:24,877 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmphqxOng/profile http://localhost:59992/getInfo.html
05:41:29 INFO - 2015-11-19 05:41:29,389 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
05:41:29 INFO - 2015-11-19 05:41:29,390 DEBUG : BROWSER_OUTPUT: colorDepth:24
05:41:29 INFO - 2015-11-19 05:41:29,390 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697
05:41:29 INFO - 2015-11-19 05:41:29,390 DEBUG : BROWSER_OUTPUT: __metrics
05:41:30 INFO - 2015-11-19 05:41:30,521 INFO : Browser initialized.
05:41:30 INFO - 2015-11-19 05:41:30,522 INFO : Running cycle 1/1 for tpaint test...
05:41:30 INFO - 2015-11-19 05:41:30,522 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmphqxOng/profile file:///builds/slave/test/build/tests/talos/talos/startup_test/tpaint.html?auto=1
05:41:58 INFO - 2015-11-19 05:41:58,803 DEBUG : BROWSER_OUTPUT: __start_report267.27999999999975|272.0699999999997|272.5|272.65999999999985|279.4549999999999|280.28999999999905|285.1350000000002|287.0499999999993|288.84000000000003|289.22999999999956|306.2099999999991|307.1399999999994|323.1449999999968|327.04499999999825|329.1749999999993|335.7399999999998|343.2099999999991|349.0699999999997|385.6850000000013|412.65499999999884__end_report__startTimestamp1447940518800__endTimestamp
05:41:58 INFO - 2015-11-19 05:41:58,803 DEBUG : BROWSER_OUTPUT: openingTimes=272.0699999999997,272.5,272.65999999999985,279.4549999999999,280.28999999999905,285.1350000000002,287.0499999999993,288.84000000000003,289.22999999999956,306.2099999999991,307.1399999999994,323.1449999999968,327.04499999999825,329.1749999999993,335.7399999999998,343.2099999999991,349.0699999999997,385.6850000000013,412.65499999999884
05:41:58 INFO - 2015-11-19 05:41:58,803 DEBUG : BROWSER_OUTPUT: avgOpenTime:310.68
05:41:58 INFO - 2015-11-19 05:41:58,803 DEBUG : BROWSER_OUTPUT: minOpenTime:267.28
05:41:58 INFO - 2015-11-19 05:41:58,803 DEBUG : BROWSER_OUTPUT: maxOpenTime:412.65
05:41:58 INFO - 2015-11-19 05:41:58,803 DEBUG : BROWSER_OUTPUT: medOpenTime:297.71999999999935
05:41:58 INFO - 2015-11-19 05:41:58,804 DEBUG : BROWSER_OUTPUT: __xulWinOpenTime:297.71999999999935
05:41:59 INFO - 2015-11-19 05:41:59,793 INFO : Browser exited with error code: 0
05:41:59 INFO - 2015-11-19 05:41:59,805 INFO : Completed test tpaint (00:00:34)
05:41:59 INFO - 2015-11-19 05:41:59,805 INFO : Starting test sessionrestore
05:41:59 INFO - 2015-11-19 05:41:59,805 DEBUG : operating with platform_type : linux_
05:41:59 INFO - 2015-11-19 05:41:59,805 INFO : Initialising browser for sessionrestore test...
05:41:59 INFO - 2015-11-19 05:41:59,814 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVSLCRI/profile http://localhost:59992/getInfo.html
05:42:07 INFO - 2015-11-19 05:42:07,761 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
05:42:07 INFO - 2015-11-19 05:42:07,761 DEBUG : BROWSER_OUTPUT: colorDepth:24
05:42:07 INFO - 2015-11-19 05:42:07,761 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1151/811
05:42:07 INFO - 2015-11-19 05:42:07,761 DEBUG : BROWSER_OUTPUT: __metrics
05:42:08 ERROR - 2015-11-19 05:42:08,099 DEBUG : BROWSER_OUTPUT: JavaScript error: chrome://browser/content/browser.js, line 17087: TypeError: browser.permitUnload is not a function
05:42:08 ERROR - 2015-11-19 05:42:08,578 DEBUG : BROWSER_OUTPUT: JavaScript error: chrome://browser/content/browser.js, line 17087: TypeError: browser.permitUnload is not a function
05:42:09 INFO - 2015-11-19 05:42:09,513 INFO : Browser initialized.
05:42:09 INFO - 2015-11-19 05:42:09,514 INFO : Running cycle 1/10 for sessionrestore test...
05:42:09 INFO - 2015-11-19 05:42:09,514 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpVSLCRI/profile/sessionstore.js
05:42:09 INFO - 2015-11-19 05:42:09,516 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpVSLCRI/profile/sessionCheckpoints.json
05:42:09 INFO - 2015-11-19 05:42:09,517 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVSLCRI/profile http://localhost:59992/startup_test/sessionrestore/index.html
05:42:15 INFO - 2015-11-19 05:42:15,242 DEBUG : BROWSER_OUTPUT: __start_report1523__end_report
05:42:15 INFO - 2015-11-19 05:42:15,242 DEBUG : BROWSER_OUTPUT:
05:42:15 INFO - 2015-11-19 05:42:15,243 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940535238__endTimestamp
05:42:15 INFO - 2015-11-19 05:42:15,243 DEBUG : BROWSER_OUTPUT:
05:42:16 INFO - 2015-11-19 05:42:16,853 INFO : Browser exited with error code: 0
05:42:16 INFO - 2015-11-19 05:42:16,855 INFO : Running cycle 2/10 for sessionrestore test...
05:42:16 INFO - 2015-11-19 05:42:16,855 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpVSLCRI/profile/sessionstore.js
05:42:16 INFO - 2015-11-19 05:42:16,857 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpVSLCRI/profile/sessionCheckpoints.json
05:42:16 INFO - 2015-11-19 05:42:16,858 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVSLCRI/profile http://localhost:59992/startup_test/sessionrestore/index.html
05:42:22 INFO - 2015-11-19 05:42:22,024 DEBUG : BROWSER_OUTPUT: __start_report1187__end_report
05:42:22 INFO - 2015-11-19 05:42:22,025 DEBUG : BROWSER_OUTPUT:
05:42:22 INFO - 2015-11-19 05:42:22,025 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940542021__endTimestamp
05:42:22 INFO - 2015-11-19 05:42:22,025 DEBUG : BROWSER_OUTPUT:
05:42:23 INFO - 2015-11-19 05:42:23,577 INFO : Browser exited with error code: 0
05:42:23 INFO - 2015-11-19 05:42:23,579 INFO : Running cycle 3/10 for sessionrestore test...
05:42:23 INFO - 2015-11-19 05:42:23,579 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpVSLCRI/profile/sessionstore.js
05:42:23 INFO - 2015-11-19 05:42:23,581 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpVSLCRI/profile/sessionCheckpoints.json
05:42:23 INFO - 2015-11-19 05:42:23,582 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVSLCRI/profile http://localhost:59992/startup_test/sessionrestore/index.html
05:42:28 INFO - 2015-11-19 05:42:28,761 DEBUG : BROWSER_OUTPUT: __start_report1181__end_report
05:42:28 INFO - 2015-11-19 05:42:28,762 DEBUG : BROWSER_OUTPUT:
05:42:28 INFO - 2015-11-19 05:42:28,762 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940548758__endTimestamp
05:42:28 INFO - 2015-11-19 05:42:28,762 DEBUG : BROWSER_OUTPUT:
05:42:30 INFO - 2015-11-19 05:42:30,349 INFO : Browser exited with error code: 0
05:42:30 INFO - 2015-11-19 05:42:30,351 INFO : Running cycle 4/10 for sessionrestore test...
05:42:30 INFO - 2015-11-19 05:42:30,351 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpVSLCRI/profile/sessionstore.js
05:42:30 INFO - 2015-11-19 05:42:30,353 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpVSLCRI/profile/sessionCheckpoints.json
05:42:30 INFO - 2015-11-19 05:42:30,354 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVSLCRI/profile http://localhost:59992/startup_test/sessionrestore/index.html
05:42:35 INFO - 2015-11-19 05:42:35,542 DEBUG : BROWSER_OUTPUT: __start_report1178__end_report
05:42:35 INFO - 2015-11-19 05:42:35,543 DEBUG : BROWSER_OUTPUT:
05:42:35 INFO - 2015-11-19 05:42:35,543 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940555540__endTimestamp
05:42:35 INFO - 2015-11-19 05:42:35,543 DEBUG : BROWSER_OUTPUT:
05:42:37 INFO - 2015-11-19 05:42:37,297 INFO : Browser exited with error code: 0
05:42:37 INFO - 2015-11-19 05:42:37,299 INFO : Running cycle 5/10 for sessionrestore test...
05:42:37 INFO - 2015-11-19 05:42:37,299 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpVSLCRI/profile/sessionstore.js
05:42:37 INFO - 2015-11-19 05:42:37,301 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpVSLCRI/profile/sessionCheckpoints.json
05:42:37 INFO - 2015-11-19 05:42:37,302 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVSLCRI/profile http://localhost:59992/startup_test/sessionrestore/index.html
05:42:42 INFO - 2015-11-19 05:42:42,424 DEBUG : BROWSER_OUTPUT: __start_report1185__end_report
05:42:42 INFO - 2015-11-19 05:42:42,424 DEBUG : BROWSER_OUTPUT:
05:42:42 INFO - 2015-11-19 05:42:42,425 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940562422__endTimestamp
05:42:42 INFO - 2015-11-19 05:42:42,425 DEBUG : BROWSER_OUTPUT:
05:42:44 INFO - 2015-11-19 05:42:44,173 INFO : Browser exited with error code: 0
05:42:44 INFO - 2015-11-19 05:42:44,175 INFO : Running cycle 6/10 for sessionrestore test...
05:42:44 INFO - 2015-11-19 05:42:44,175 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpVSLCRI/profile/sessionstore.js
05:42:44 INFO - 2015-11-19 05:42:44,177 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpVSLCRI/profile/sessionCheckpoints.json
05:42:44 INFO - 2015-11-19 05:42:44,178 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVSLCRI/profile http://localhost:59992/startup_test/sessionrestore/index.html
05:42:49 INFO - 2015-11-19 05:42:49,348 DEBUG : BROWSER_OUTPUT: __start_report1178__end_report
05:42:49 INFO - 2015-11-19 05:42:49,348 DEBUG : BROWSER_OUTPUT:
05:42:49 INFO - 2015-11-19 05:42:49,348 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940569345__endTimestamp
05:42:49 INFO - 2015-11-19 05:42:49,348 DEBUG : BROWSER_OUTPUT:
05:42:50 INFO - 2015-11-19 05:42:50,185 DEBUG : BROWSER_OUTPUT: [Child 8049] WARNING: pipe error (3): Connection reset by peer: file /builds/slave/fx-team-l64-000000000000000000/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 459
05:42:50 INFO - 2015-11-19 05:42:50,185 DEBUG : BROWSER_OUTPUT:
05:42:50 INFO - 2015-11-19 05:42:50,185 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
05:42:50 INFO - 2015-11-19 05:42:50,185 DEBUG : BROWSER_OUTPUT:
05:42:50 INFO - 2015-11-19 05:42:50,186 DEBUG : BROWSER_OUTPUT:
05:42:50 INFO - 2015-11-19 05:42:50,187 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
05:42:50 INFO - 2015-11-19 05:42:50,187 DEBUG : BROWSER_OUTPUT:
05:42:50 INFO - 2015-11-19 05:42:50,187 DEBUG : BROWSER_OUTPUT:
05:42:50 INFO - 2015-11-19 05:42:50,187 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
05:42:50 INFO - 2015-11-19 05:42:50,187 DEBUG : BROWSER_OUTPUT:
05:42:50 INFO - 2015-11-19 05:42:50,187 DEBUG : BROWSER_OUTPUT:
05:42:50 INFO - 2015-11-19 05:42:50,187 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
05:42:50 INFO - 2015-11-19 05:42:50,187 DEBUG : BROWSER_OUTPUT:
05:42:50 INFO - 2015-11-19 05:42:50,187 DEBUG : BROWSER_OUTPUT:
05:42:50 INFO - 2015-11-19 05:42:50,188 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
05:42:50 INFO - 2015-11-19 05:42:50,188 DEBUG : BROWSER_OUTPUT:
05:42:51 INFO - 2015-11-19 05:42:51,033 INFO : Browser exited with error code: 0
05:42:51 INFO - 2015-11-19 05:42:51,035 INFO : Running cycle 7/10 for sessionrestore test...
05:42:51 INFO - 2015-11-19 05:42:51,035 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpVSLCRI/profile/sessionstore.js
05:42:51 INFO - 2015-11-19 05:42:51,037 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpVSLCRI/profile/sessionCheckpoints.json
05:42:51 INFO - 2015-11-19 05:42:51,038 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVSLCRI/profile http://localhost:59992/startup_test/sessionrestore/index.html
05:42:56 INFO - 2015-11-19 05:42:56,189 DEBUG : BROWSER_OUTPUT: __start_report1194__end_report
05:42:56 INFO - 2015-11-19 05:42:56,189 DEBUG : BROWSER_OUTPUT:
05:42:56 INFO - 2015-11-19 05:42:56,189 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940576187__endTimestamp
05:42:56 INFO - 2015-11-19 05:42:56,189 DEBUG : BROWSER_OUTPUT:
05:42:57 INFO - 2015-11-19 05:42:57,869 INFO : Browser exited with error code: 0
05:42:57 INFO - 2015-11-19 05:42:57,871 INFO : Running cycle 8/10 for sessionrestore test...
05:42:57 INFO - 2015-11-19 05:42:57,871 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpVSLCRI/profile/sessionstore.js
05:42:57 INFO - 2015-11-19 05:42:57,873 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpVSLCRI/profile/sessionCheckpoints.json
05:42:57 INFO - 2015-11-19 05:42:57,874 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVSLCRI/profile http://localhost:59992/startup_test/sessionrestore/index.html
05:43:03 INFO - 2015-11-19 05:43:03,118 DEBUG : BROWSER_OUTPUT: __start_report1193__end_report
05:43:03 INFO - 2015-11-19 05:43:03,118 DEBUG : BROWSER_OUTPUT:
05:43:03 INFO - 2015-11-19 05:43:03,118 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940583114__endTimestamp
05:43:03 INFO - 2015-11-19 05:43:03,118 DEBUG : BROWSER_OUTPUT:
05:43:04 INFO - 2015-11-19 05:43:04,813 INFO : Browser exited with error code: 0
05:43:04 INFO - 2015-11-19 05:43:04,815 INFO : Running cycle 9/10 for sessionrestore test...
05:43:04 INFO - 2015-11-19 05:43:04,815 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpVSLCRI/profile/sessionstore.js
05:43:04 INFO - 2015-11-19 05:43:04,817 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpVSLCRI/profile/sessionCheckpoints.json
05:43:04 INFO - 2015-11-19 05:43:04,818 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVSLCRI/profile http://localhost:59992/startup_test/sessionrestore/index.html
05:43:10 INFO - 2015-11-19 05:43:10,123 DEBUG : BROWSER_OUTPUT: __start_report1183__end_report
05:43:10 INFO - 2015-11-19 05:43:10,123 DEBUG : BROWSER_OUTPUT:
05:43:10 INFO - 2015-11-19 05:43:10,123 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940590121__endTimestamp
05:43:10 INFO - 2015-11-19 05:43:10,123 DEBUG : BROWSER_OUTPUT:
05:43:11 INFO - 2015-11-19 05:43:11,021 DEBUG : BROWSER_OUTPUT: [Child 8403] WARNING: pipe error (3): Connection reset by peer: file /builds/slave/fx-team-l64-000000000000000000/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 459
05:43:11 INFO - 2015-11-19 05:43:11,893 INFO : Browser exited with error code: 0
05:43:11 INFO - 2015-11-19 05:43:11,895 INFO : Running cycle 10/10 for sessionrestore test...
05:43:11 INFO - 2015-11-19 05:43:11,895 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpVSLCRI/profile/sessionstore.js
05:43:11 INFO - 2015-11-19 05:43:11,897 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpVSLCRI/profile/sessionCheckpoints.json
05:43:11 INFO - 2015-11-19 05:43:11,898 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVSLCRI/profile http://localhost:59992/startup_test/sessionrestore/index.html
05:43:17 INFO - 2015-11-19 05:43:17,048 DEBUG : BROWSER_OUTPUT: __start_report1178__end_report
05:43:17 INFO - 2015-11-19 05:43:17,048 DEBUG : BROWSER_OUTPUT:
05:43:17 INFO - 2015-11-19 05:43:17,048 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940597046__endTimestamp
05:43:17 INFO - 2015-11-19 05:43:17,048 DEBUG : BROWSER_OUTPUT:
05:43:18 INFO - 2015-11-19 05:43:18,745 INFO : Browser exited with error code: 0
05:43:18 INFO - 2015-11-19 05:43:18,764 INFO : Completed test sessionrestore (00:01:18)
05:43:18 INFO - 2015-11-19 05:43:18,764 INFO : Starting test sessionrestore_no_auto_restore
05:43:18 INFO - 2015-11-19 05:43:18,764 DEBUG : operating with platform_type : linux_
05:43:18 INFO - 2015-11-19 05:43:18,764 INFO : Initialising browser for sessionrestore_no_auto_restore test...
05:43:18 INFO - 2015-11-19 05:43:18,773 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp5hQUy8/profile http://localhost:59992/getInfo.html
05:43:23 INFO - 2015-11-19 05:43:23,042 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
05:43:23 INFO - 2015-11-19 05:43:23,042 DEBUG : BROWSER_OUTPUT: colorDepth:24
05:43:23 INFO - 2015-11-19 05:43:23,042 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1151/811
05:43:23 INFO - 2015-11-19 05:43:23,042 DEBUG : BROWSER_OUTPUT: __metrics
05:43:24 INFO - 2015-11-19 05:43:24,137 INFO : Browser initialized.
05:43:24 INFO - 2015-11-19 05:43:24,138 INFO : Running cycle 1/10 for sessionrestore_no_auto_restore test...
05:43:24 INFO - 2015-11-19 05:43:24,138 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp5hQUy8/profile/sessionstore.js
05:43:24 INFO - 2015-11-19 05:43:24,140 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp5hQUy8/profile/sessionCheckpoints.json
05:43:24 INFO - 2015-11-19 05:43:24,141 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp5hQUy8/profile http://localhost:59992/startup_test/sessionrestore/index.html
05:43:26 INFO - 2015-11-19 05:43:26,237 DEBUG : BROWSER_OUTPUT: __start_report1113__end_report
05:43:26 INFO - 2015-11-19 05:43:26,238 DEBUG : BROWSER_OUTPUT:
05:43:26 INFO - 2015-11-19 05:43:26,238 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940606230__endTimestamp
05:43:26 INFO - 2015-11-19 05:43:26,238 DEBUG : BROWSER_OUTPUT:
05:43:27 INFO - 2015-11-19 05:43:27,217 INFO : Browser exited with error code: 0
05:43:27 INFO - 2015-11-19 05:43:27,219 INFO : Running cycle 2/10 for sessionrestore_no_auto_restore test...
05:43:27 INFO - 2015-11-19 05:43:27,219 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp5hQUy8/profile/sessionstore.js
05:43:27 INFO - 2015-11-19 05:43:27,221 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp5hQUy8/profile/sessionCheckpoints.json
05:43:27 INFO - 2015-11-19 05:43:27,222 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp5hQUy8/profile http://localhost:59992/startup_test/sessionrestore/index.html
05:43:28 INFO - 2015-11-19 05:43:28,834 DEBUG : BROWSER_OUTPUT: __start_report745__end_report
05:43:28 INFO - 2015-11-19 05:43:28,834 DEBUG : BROWSER_OUTPUT:
05:43:28 INFO - 2015-11-19 05:43:28,834 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940608827__endTimestamp
05:43:28 INFO - 2015-11-19 05:43:28,834 DEBUG : BROWSER_OUTPUT:
05:43:29 INFO - 2015-11-19 05:43:29,797 INFO : Browser exited with error code: 0
05:43:29 INFO - 2015-11-19 05:43:29,799 INFO : Running cycle 3/10 for sessionrestore_no_auto_restore test...
05:43:29 INFO - 2015-11-19 05:43:29,799 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp5hQUy8/profile/sessionstore.js
05:43:29 INFO - 2015-11-19 05:43:29,801 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp5hQUy8/profile/sessionCheckpoints.json
05:43:29 INFO - 2015-11-19 05:43:29,801 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp5hQUy8/profile http://localhost:59992/startup_test/sessionrestore/index.html
05:43:31 INFO - 2015-11-19 05:43:31,415 DEBUG : BROWSER_OUTPUT: __start_report784__end_report
05:43:31 INFO - 2015-11-19 05:43:31,415 DEBUG : BROWSER_OUTPUT:
05:43:31 INFO - 2015-11-19 05:43:31,415 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940611412__endTimestamp
05:43:31 INFO - 2015-11-19 05:43:31,415 DEBUG : BROWSER_OUTPUT:
05:43:32 INFO - 2015-11-19 05:43:32,393 INFO : Browser exited with error code: 0
05:43:32 INFO - 2015-11-19 05:43:32,395 INFO : Running cycle 4/10 for sessionrestore_no_auto_restore test...
05:43:32 INFO - 2015-11-19 05:43:32,395 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp5hQUy8/profile/sessionstore.js
05:43:32 INFO - 2015-11-19 05:43:32,397 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp5hQUy8/profile/sessionCheckpoints.json
05:43:32 INFO - 2015-11-19 05:43:32,397 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp5hQUy8/profile http://localhost:59992/startup_test/sessionrestore/index.html
05:43:34 INFO - 2015-11-19 05:43:34,031 DEBUG : BROWSER_OUTPUT: __start_report771__end_report
05:43:34 INFO - 2015-11-19 05:43:34,032 DEBUG : BROWSER_OUTPUT:
05:43:34 INFO - 2015-11-19 05:43:34,032 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940614030__endTimestamp
05:43:34 INFO - 2015-11-19 05:43:34,032 DEBUG : BROWSER_OUTPUT:
05:43:35 INFO - 2015-11-19 05:43:35,089 INFO : Browser exited with error code: 0
05:43:35 INFO - 2015-11-19 05:43:35,091 INFO : Running cycle 5/10 for sessionrestore_no_auto_restore test...
05:43:35 INFO - 2015-11-19 05:43:35,091 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp5hQUy8/profile/sessionstore.js
05:43:35 INFO - 2015-11-19 05:43:35,093 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp5hQUy8/profile/sessionCheckpoints.json
05:43:35 INFO - 2015-11-19 05:43:35,093 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp5hQUy8/profile http://localhost:59992/startup_test/sessionrestore/index.html
05:43:36 INFO - 2015-11-19 05:43:36,698 DEBUG : BROWSER_OUTPUT: __start_report766__end_report
05:43:36 INFO - 2015-11-19 05:43:36,698 DEBUG : BROWSER_OUTPUT:
05:43:36 INFO - 2015-11-19 05:43:36,699 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940616696__endTimestamp
05:43:36 INFO - 2015-11-19 05:43:36,699 DEBUG : BROWSER_OUTPUT:
05:43:37 INFO - 2015-11-19 05:43:37,713 INFO : Browser exited with error code: 0
05:43:37 INFO - 2015-11-19 05:43:37,715 INFO : Running cycle 6/10 for sessionrestore_no_auto_restore test...
05:43:37 INFO - 2015-11-19 05:43:37,715 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp5hQUy8/profile/sessionstore.js
05:43:37 INFO - 2015-11-19 05:43:37,717 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp5hQUy8/profile/sessionCheckpoints.json
05:43:37 INFO - 2015-11-19 05:43:37,717 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp5hQUy8/profile http://localhost:59992/startup_test/sessionrestore/index.html
05:43:39 INFO - 2015-11-19 05:43:39,312 DEBUG : BROWSER_OUTPUT: __start_report772__end_report
05:43:39 INFO - 2015-11-19 05:43:39,312 DEBUG : BROWSER_OUTPUT:
05:43:39 INFO - 2015-11-19 05:43:39,312 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940619311__endTimestamp
05:43:39 INFO - 2015-11-19 05:43:39,313 DEBUG : BROWSER_OUTPUT:
05:43:40 INFO - 2015-11-19 05:43:40,417 INFO : Browser exited with error code: 0
05:43:40 INFO - 2015-11-19 05:43:40,419 INFO : Running cycle 7/10 for sessionrestore_no_auto_restore test...
05:43:40 INFO - 2015-11-19 05:43:40,419 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp5hQUy8/profile/sessionstore.js
05:43:40 INFO - 2015-11-19 05:43:40,421 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp5hQUy8/profile/sessionCheckpoints.json
05:43:40 INFO - 2015-11-19 05:43:40,421 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp5hQUy8/profile http://localhost:59992/startup_test/sessionrestore/index.html
05:43:42 INFO - 2015-11-19 05:43:42,040 DEBUG : BROWSER_OUTPUT: __start_report769__end_report
05:43:42 INFO - 2015-11-19 05:43:42,040 DEBUG : BROWSER_OUTPUT:
05:43:42 INFO - 2015-11-19 05:43:42,040 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940622035__endTimestamp
05:43:42 INFO - 2015-11-19 05:43:42,040 DEBUG : BROWSER_OUTPUT:
05:43:43 INFO - 2015-11-19 05:43:43,161 INFO : Browser exited with error code: 0
05:43:43 INFO - 2015-11-19 05:43:43,163 INFO : Running cycle 8/10 for sessionrestore_no_auto_restore test...
05:43:43 INFO - 2015-11-19 05:43:43,163 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp5hQUy8/profile/sessionstore.js
05:43:43 INFO - 2015-11-19 05:43:43,165 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp5hQUy8/profile/sessionCheckpoints.json
05:43:43 INFO - 2015-11-19 05:43:43,166 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp5hQUy8/profile http://localhost:59992/startup_test/sessionrestore/index.html
05:43:44 INFO - 2015-11-19 05:43:44,785 DEBUG : BROWSER_OUTPUT: __start_report800__end_report
05:43:44 INFO - 2015-11-19 05:43:44,786 DEBUG : BROWSER_OUTPUT:
05:43:44 INFO - 2015-11-19 05:43:44,786 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940624785__endTimestamp
05:43:44 INFO - 2015-11-19 05:43:44,786 DEBUG : BROWSER_OUTPUT:
05:43:45 INFO - 2015-11-19 05:43:45,845 INFO : Browser exited with error code: 0
05:43:45 INFO - 2015-11-19 05:43:45,847 INFO : Running cycle 9/10 for sessionrestore_no_auto_restore test...
05:43:45 INFO - 2015-11-19 05:43:45,847 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp5hQUy8/profile/sessionstore.js
05:43:45 INFO - 2015-11-19 05:43:45,849 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp5hQUy8/profile/sessionCheckpoints.json
05:43:45 INFO - 2015-11-19 05:43:45,850 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp5hQUy8/profile http://localhost:59992/startup_test/sessionrestore/index.html
05:43:47 INFO - 2015-11-19 05:43:47,424 DEBUG : BROWSER_OUTPUT: __start_report749__end_report
05:43:47 INFO - 2015-11-19 05:43:47,424 DEBUG : BROWSER_OUTPUT:
05:43:47 INFO - 2015-11-19 05:43:47,424 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940627421__endTimestamp
05:43:47 INFO - 2015-11-19 05:43:47,424 DEBUG : BROWSER_OUTPUT:
05:43:48 INFO - 2015-11-19 05:43:48,545 INFO : Browser exited with error code: 0
05:43:48 INFO - 2015-11-19 05:43:48,547 INFO : Running cycle 10/10 for sessionrestore_no_auto_restore test...
05:43:48 INFO - 2015-11-19 05:43:48,547 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp5hQUy8/profile/sessionstore.js
05:43:48 INFO - 2015-11-19 05:43:48,549 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp5hQUy8/profile/sessionCheckpoints.json
05:43:48 INFO - 2015-11-19 05:43:48,550 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp5hQUy8/profile http://localhost:59992/startup_test/sessionrestore/index.html
05:43:50 INFO - 2015-11-19 05:43:50,197 DEBUG : BROWSER_OUTPUT: __start_report754__end_report
05:43:50 INFO - 2015-11-19 05:43:50,197 DEBUG : BROWSER_OUTPUT:
05:43:50 INFO - 2015-11-19 05:43:50,197 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940630194__endTimestamp
05:43:50 INFO - 2015-11-19 05:43:50,197 DEBUG : BROWSER_OUTPUT:
05:43:51 INFO - 2015-11-19 05:43:51,273 INFO : Browser exited with error code: 0
05:43:51 INFO - 2015-11-19 05:43:51,294 INFO : Completed test sessionrestore_no_auto_restore (00:00:32)
05:43:51 INFO - 2015-11-19 05:43:51,610 INFO : Completed test suite (00:05:17)
05:43:51 INFO - 2015-11-19 05:43:51,610 DEBUG : Working with test: a11yr
05:43:51 INFO - 2015-11-19 05:43:51,610 DEBUG : Generating results file: a11yr
05:43:51 INFO - 2015-11-19 05:43:51,610 DEBUG : Working with test: ts_paint
05:43:51 INFO - 2015-11-19 05:43:51,610 DEBUG : Generating results file: ts_paint
05:43:51 INFO - 2015-11-19 05:43:51,611 DEBUG : Working with test: tpaint
05:43:51 INFO - 2015-11-19 05:43:51,612 DEBUG : Generating results file: tpaint
05:43:51 INFO - 2015-11-19 05:43:51,612 DEBUG : Working with test: sessionrestore
05:43:51 INFO - 2015-11-19 05:43:51,612 DEBUG : Generating results file: sessionrestore
05:43:51 INFO - 2015-11-19 05:43:51,612 DEBUG : Working with test: sessionrestore_no_auto_restore
05:43:51 INFO - 2015-11-19 05:43:51,613 DEBUG : Generating results file: sessionrestore_no_auto_restore
05:43:51 INFO - 2015-11-19 05:43:51,613 INFO : Posting result 0 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
05:43:51 INFO - 2015-11-19 05:43:51,656 DEBUG : process_Request line: a11yr_paint graph.html#tests=[[223,132,43]]
05:43:51 INFO - 2015-11-19 05:43:51,656 DEBUG : process_Request line: a11yr_paint 717.49 graph.html#tests=[[223,132,43]]
05:43:51 INFO - 2015-11-19 05:43:51,656 INFO : Posting result 1 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
05:43:51 INFO - 2015-11-19 05:43:51,715 DEBUG : process_Request line: ts_paint graph.html#tests=[[83,132,43]]
05:43:51 INFO - 2015-11-19 05:43:51,715 DEBUG : process_Request line: ts_paint 532.80 graph.html#tests=[[83,132,43]]
05:43:51 INFO - 2015-11-19 05:43:51,716 INFO : Posting result 2 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
05:43:51 INFO - 2015-11-19 05:43:51,744 DEBUG : process_Request line: tpaint graph.html#tests=[[82,132,43]]
05:43:51 INFO - 2015-11-19 05:43:51,744 DEBUG : process_Request line: tpaint 323.14 graph.html#tests=[[82,132,43]]
05:43:51 INFO - 2015-11-19 05:43:51,744 INFO : Posting result 3 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
05:43:51 INFO - 2015-11-19 05:43:51,785 DEBUG : process_Request line: sessionrestore graph.html#tests=[[313,132,43]]
05:43:51 INFO - 2015-11-19 05:43:51,785 DEBUG : process_Request line: sessionrestore 1214.28 graph.html#tests=[[313,132,43]]
05:43:51 INFO - 2015-11-19 05:43:51,785 INFO : Posting result 4 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
05:43:51 INFO - 2015-11-19 05:43:51,830 DEBUG : process_Request line: sessionrestore_no_auto_restore graph.html#tests=[[315,132,43]]
05:43:51 INFO - 2015-11-19 05:43:51,830 DEBUG : process_Request line: sessionrestore_no_auto_restore 796.67 graph.html#tests=[[315,132,43]]
05:43:51 INFO - 2015-11-19 05:43:51,831 INFO : PERFHERDER_DATA: {"framework": {"name": "talos"}, "suites": [{"lowerIsBetter": true, "subtests": [{"lowerIsBetter": true, "replicates": [1261.0, 1299.0, 1307.0, 1341.0, 1328.0, 1323.0, 1344.0, 1330.0, 1524.0, 1525.0, 1315.0, 1325.0, 1526.0, 1334.0, 1527.0, 1322.0, 1316.0, 1313.0, 1348.0, 1324.0, 1331.0, 1329.0, 1333.0, 1339.0, 1320.0], "unit": "ms", "name": "dhtml.html", "value": 1329.5}, {"lowerIsBetter": true, "replicates": [380.0, 381.0, 377.0, 383.0, 390.0, 388.0, 378.0, 390.0, 378.0, 392.0, 387.0, 385.0, 399.0, 377.0, 388.0, 393.0, 393.0, 387.0, 402.0, 384.0, 380.0, 379.0, 387.0, 397.0, 386.0], "unit": "ms", "name": "tablemutation.html", "value": 387.0}], "name": "a11yr", "value": 717.4942588497139}, {"subtests": [{"replicates": [480.0, 571.0, 511.0, 523.0, 519.0, 520.0, 523.0, 554.0, 504.0, 618.0, 520.0, 554.0, 549.0, 517.0, 541.0, 503.0, 534.0, 562.0, 513.0, 556.0], "name": "ts_paint", "value": 523.0}], "name": "ts_paint", "value": 523.0}, {"subtests": [{"replicates": [267.27999999999975, 272.0699999999997, 272.5, 272.65999999999985, 279.4549999999999, 280.28999999999905, 285.1350000000002, 287.0499999999993, 288.84000000000003, 289.22999999999956, 306.2099999999991, 307.1399999999994, 323.1449999999968, 327.04499999999825, 329.1749999999993, 335.7399999999998, 343.2099999999991, 349.0699999999997, 385.6850000000013, 412.65499999999884], "name": "tpaint", "value": 323.1449999999968}], "name": "tpaint", "value": 323.1449999999968}, {"subtests": [{"replicates": [1523.0, 1187.0, 1181.0, 1178.0, 1185.0, 1178.0, 1194.0, 1193.0, 1183.0, 1178.0], "name": "sessionrestore", "value": 1183.0}], "name": "sessionrestore", "value": 1183.0}, {"subtests": [{"replicates": [1113.0, 745.0, 784.0, 771.0, 766.0, 772.0, 769.0, 800.0, 749.0, 754.0], "name": "sessionrestore_no_auto_restore", "value": 769.0}], "name": "sessionrestore_no_auto_restore", "value": 769.0}]}
05:43:51 INFO - RETURN: a11yr_paint: 717.49
05:43:51 INFO - RETURN: ts_paint: 532.80
05:43:51 INFO - RETURN: tpaint: 323.14
05:43:51 INFO - RETURN: sessionrestore: 1214.28
05:43:51 INFO - RETURN: sessionrestore_no_auto_restore: 796.67
05:43:51 INFO - TinderboxPrint: TalosResult: {"graphserver": {"sessionrestore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[313,132,43]]", "result": "1214.28"}, "a11yr_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[223,132,43]]", "result": "717.49"}, "tpaint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[82,132,43]]", "result": "323.14"}, "ts_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[83,132,43]]", "result": "532.80"}, "sessionrestore_no_auto_restore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[315,132,43]]", "result": "796.67"}}}
05:43:51 INFO - Return code: 0
05:43:51 ERROR - # TBPL SUCCESS #
05:43:51 INFO - Running post-action listener: _resource_record_post_action
05:43:51 INFO - Running post-run listener: _resource_record_post_run
05:43:52 INFO - Total resource usage - Wall time: 331s; CPU: 16.0%; Read bytes: 28672; Write bytes: 568246272; Read time: 176; Write time: 380392
05:43:52 INFO - install - Wall time: 14s; CPU: 13.0%; Read bytes: 4096; Write bytes: 159371264; Read time: 68; Write time: 153444
05:43:52 INFO - run-tests - Wall time: 318s; CPU: 16.0%; Read bytes: 20480; Write bytes: 340631552; Read time: 24; Write time: 169560
05:43:52 INFO - Running post-run listener: _upload_blobber_files
05:43:52 INFO - Blob upload gear active.
05:43:52 INFO - There are no files to upload in the directory. Skipping the blob upload mechanism ...
05:43:52 INFO - Copying logs to upload dir...
05:43:52 INFO - mkdir: /builds/slave/test/build/upload/logs
program finished with exit code 0
elapsedTime=377.785737
========= master_lag: 0.02 =========
========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 6 mins, 17 secs) (at 2015-11-19 05:43:52.720985) =========
========= Started set props: build_url (results: 0, elapsed: 0 secs) (at 2015-11-19 05:43:52.724443) =========
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=61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
build_url:https://queue.taskcluster.net/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2
program finished with exit code 0
elapsedTime=0.010179
build_url: 'https://queue.taskcluster.net/v1/task/hn_i-YmOSISiPFOXjDDJJg/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-19 05:43:52.774849) =========
========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-11-19 05:43:52.775177) =========
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=61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
program finished with exit code 0
elapsedTime=0.004549
========= master_lag: 0.05 =========
========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-11-19 05:43:52.825292) =========
========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2015-11-19 05:43:52.825590) =========
========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2015-11-19 05:43:52.825871) =========
========= Total master_lag: 0.23 =========