builder: fx-team_ubuntu64_hw_test-other-e10s
slave: talos-linux64-ix-053
starttime: 1448312284.51
results: success (0)
buildid: 20151120090830
builduid: 9b3dc1bd24354a9aacec687cccc2ce8f
revision: a0db720c980e3fbacf92c03566e8ffea5fdefd2d
========= Started set props: master (results: 0, elapsed: 0 secs) (at 2015-11-23 12:58:04.510010) =========
master: http://buildbot-master105.bb.releng.scl3.mozilla.com:8201/
========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2015-11-23 12:58:04.510682) =========
========= Started set props: basedir (results: 0, elapsed: 0 secs) (at 2015-11-23 12:58:04.511139) =========
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=919420d7ee4ef147bef0346300000385-1448312283.868710-972446830
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
/builds/slave/test
program finished with exit code 0
elapsedTime=0.006469
basedir: '/builds/slave/test'
========= master_lag: 0.02 =========
========= Finished set props: basedir (results: 0, elapsed: 0 secs) (at 2015-11-23 12:58:04.541766) =========
========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-11-23 12:58:04.542069) =========
========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-11-23 12:58:04.556297) =========
========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-23 12:58:04.556730) =========
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=919420d7ee4ef147bef0346300000385-1448312283.868710-972446830
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
program finished with exit code 0
elapsedTime=0.004591
========= master_lag: 0.05 =========
========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-23 12:58:04.606926) =========
========= Started set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-11-23 12:58:04.607260) =========
script_repo_url: https://hg.mozilla.org/build/mozharness
========= Finished set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-11-23 12:58:04.607642) =========
========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-23 12:58:04.607917) =========
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=919420d7ee4ef147bef0346300000385-1448312283.868710-972446830
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
--2015-11-23 12:58:04-- 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% 8.24M=0.001s
2015-11-23 12:58:04 (8.24 MB/s) - `archiver_client.py' saved [12141/12141]
program finished with exit code 0
elapsedTime=0.095794
========= master_lag: 0.01 =========
========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-23 12:58:04.716197) =========
========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-23 12:58:04.716551) =========
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=919420d7ee4ef147bef0346300000385-1448312283.868710-972446830
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
program finished with exit code 0
elapsedTime=0.022594
========= master_lag: 0.03 =========
========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-23 12:58:04.766318) =========
========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-23 12:58:04.766681) =========
bash -c 'python archiver_client.py mozharness --repo integration/fx-team --rev a0db720c980e3fbacf92c03566e8ffea5fdefd2d --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 a0db720c980e3fbacf92c03566e8ffea5fdefd2d --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=919420d7ee4ef147bef0346300000385-1448312283.868710-972446830
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
2015-11-23 12:58:04,957 truncating revision to first 12 chars
2015-11-23 12:58:04,958 Setting DEBUG logging.
2015-11-23 12:58:04,958 attempt 1/10
2015-11-23 12:58:04,958 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/integration/fx-team/a0db720c980e?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness
2015-11-23 12:58:05,464 unpacking tar archive at: fx-team-a0db720c980e/testing/mozharness/
program finished with exit code 0
elapsedTime=0.799209
========= master_lag: 0.02 =========
========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-23 12:58:05.581025) =========
========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-11-23 12:58:05.581775) =========
========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-11-23 12:58:05.594108) =========
========= Started tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-11-23 12:58:05.594674) =========
TinderboxPrint: script_revlink: https://hg.mozilla.org/build/mozharness/rev/production
========= Finished tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-11-23 12:58:05.595347) =========
========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 5 mins, 51 secs) (at 2015-11-23 12:58:05.595822) =========
/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=919420d7ee4ef147bef0346300000385-1448312283.868710-972446830
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
12:58:05 INFO - MultiFileLogger online at 20151123 12:58:05 in /builds/slave/test
12:58:05 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
12:58:05 INFO - Dumping config to /builds/slave/test/logs/localconfig.json.
12:58:05 INFO - {'append_to_log': False,
12:58:05 INFO - 'base_work_dir': '/builds/slave/test',
12:58:05 INFO - 'blob_upload_branch': 'Fx-Team-Non-PGO',
12:58:05 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt',
12:58:05 INFO - 'branch': 'Fx-Team-Non-PGO',
12:58:05 INFO - 'buildbot_json_path': 'buildprops.json',
12:58:05 INFO - 'config_files': ('talos/linux_config.py',),
12:58:05 INFO - 'default_actions': ('clobber',
12:58:05 INFO - 'read-buildbot-config',
12:58:05 INFO - 'download-and-extract',
12:58:05 INFO - 'populate-webroot',
12:58:05 INFO - 'create-virtualenv',
12:58:05 INFO - 'install',
12:58:05 INFO - 'run-tests'),
12:58:05 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',),
12:58:05 INFO - 'download_minidump_stackwalk': True,
12:58:05 INFO - 'download_symbols': 'ondemand',
12:58:05 INFO - 'exes': {'python': '/tools/buildbot/bin/python',
12:58:05 INFO - 'tooltool.py': '/tools/tooltool.py',
12:58:05 INFO - 'virtualenv': ('/tools/buildbot/bin/python',
12:58:05 INFO - '/tools/misc-python/virtualenv.py')},
12:58:05 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub',
12:58:05 INFO - 'http://pypi.pub.build.mozilla.org/pub'),
12:58:05 INFO - 'installer_path': 'installer.exe',
12:58:05 INFO - 'log_level': 'info',
12:58:05 INFO - 'log_name': 'talos',
12:58:05 INFO - 'log_to_console': True,
12:58:05 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk',
12:58:05 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest',
12:58:05 INFO - 'opt_config_files': (),
12:58:05 INFO - 'pip_index': False,
12:58:05 INFO - 'sps_profile': False,
12:58:05 INFO - 'sps_profile_interval': 0,
12:58:05 INFO - 'suite': 'other-e10s',
12:58:05 INFO - 'system_bits': '64',
12:58:05 INFO - 'talos_extra_options': ('--webServer', 'localhost'),
12:58:05 INFO - 'title': 'talos-linux64-ix-053',
12:58:05 INFO - 'tooltool_cache': '/builds/tooltool_cache',
12:58:05 INFO - 'use_talos_json': True,
12:58:05 INFO - 'virtualenv_path': '/builds/slave/test/build/venv',
12:58:05 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None},
12:58:05 INFO - 'work_dir': 'build'}
12:58:05 INFO - #####
12:58:05 INFO - ##### Running clobber step.
12:58:05 INFO - #####
12:58:05 INFO - Running pre-action listener: _resource_record_pre_action
12:58:05 INFO - Running main action method: clobber
12:58:05 INFO - rmtree: /builds/slave/test/build
12:58:05 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1
12:58:06 INFO - Running post-action listener: _resource_record_post_action
12:58:06 INFO - #####
12:58:06 INFO - ##### Running read-buildbot-config step.
12:58:06 INFO - #####
12:58:06 INFO - Running pre-action listener: _resource_record_pre_action
12:58:06 INFO - Running main action method: read_buildbot_config
12:58:06 INFO - Using buildbot properties:
12:58:06 INFO - {
12:58:06 INFO - "properties": {
12:58:06 INFO - "buildnumber": 328,
12:58:06 INFO - "product": "firefox",
12:58:06 INFO - "script_repo_revision": "production",
12:58:06 INFO - "builddir": "fx-team_ubuntu64_hw_test-other-e10s",
12:58:06 INFO - "repository": "",
12:58:06 INFO - "buildername": "Ubuntu HW 12.04 x64 fx-team talos other-e10s",
12:58:06 INFO - "buildid": "20151120090830",
12:58:06 INFO - "slavename": "talos-linux64-ix-053",
12:58:06 INFO - "pgo_build": "False",
12:58:06 INFO - "basedir": "/builds/slave/test",
12:58:06 INFO - "project": "",
12:58:06 INFO - "platform": "ubuntu64_hw",
12:58:06 INFO - "master": "http://buildbot-master105.bb.releng.scl3.mozilla.com:8201/",
12:58:06 INFO - "slavebuilddir": "test",
12:58:06 INFO - "scheduler": "tests-fx-team-linux64-talos",
12:58:06 INFO - "branch": "fx-team",
12:58:06 INFO - "repo_path": "integration/fx-team",
12:58:06 INFO - "stage_platform": "linux64",
12:58:06 INFO - "builduid": "9b3dc1bd24354a9aacec687cccc2ce8f",
12:58:06 INFO - "revision": "a0db720c980e3fbacf92c03566e8ffea5fdefd2d"
12:58:06 INFO - },
12:58:06 INFO - "sourcestamp": {
12:58:06 INFO - "repository": "",
12:58:06 INFO - "hasPatch": false,
12:58:06 INFO - "project": "",
12:58:06 INFO - "branch": "fx-team-linux64-talos",
12:58:06 INFO - "changes": [
12:58:06 INFO - {
12:58:06 INFO - "category": null,
12:58:06 INFO - "files": [
12:58:06 INFO - {
12:58:06 INFO - "url": null,
12:58:06 INFO - "name": "https://queue.taskcluster.net/v1/task/WsFfSGx8Qu2guP2wehmoyw/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2"
12:58:06 INFO - }
12:58:06 INFO - ],
12:58:06 INFO - "repository": "",
12:58:06 INFO - "rev": "a0db720c980e3fbacf92c03566e8ffea5fdefd2d",
12:58:06 INFO - "who": "dtownsend@mozilla.com",
12:58:06 INFO - "when": 1448041494,
12:58:06 INFO - "number": 6689725,
12:58:06 INFO - "comments": "Bug 1146926: Allow attaching a worker to a CPOW window without invoking CPOW operations. r=gabor\n\nBy sending the CPOW to the child processes the one that owns it will create the\nchild worker and then send back the url of the window to set up the parent\nside of the worker.\n\nThere are two breaking changes here. Workers invoked in this way no longer\nattach synchronously. We no longer pass the window through the attach event.",
12:58:06 INFO - "project": "",
12:58:06 INFO - "at": "Fri 20 Nov 2015 09:44:54",
12:58:06 INFO - "branch": "fx-team-linux64-talos",
12:58:06 INFO - "revlink": "",
12:58:06 INFO - "properties": [
12:58:06 INFO - [
12:58:06 INFO - "buildid",
12:58:06 INFO - "20151120090830",
12:58:06 INFO - "Change"
12:58:06 INFO - ],
12:58:06 INFO - [
12:58:06 INFO - "builduid",
12:58:06 INFO - "9b3dc1bd24354a9aacec687cccc2ce8f",
12:58:06 INFO - "Change"
12:58:06 INFO - ],
12:58:06 INFO - [
12:58:06 INFO - "pgo_build",
12:58:06 INFO - "False",
12:58:06 INFO - "Change"
12:58:06 INFO - ]
12:58:06 INFO - ],
12:58:06 INFO - "revision": "a0db720c980e3fbacf92c03566e8ffea5fdefd2d"
12:58:06 INFO - }
12:58:06 INFO - ],
12:58:06 INFO - "revision": "a0db720c980e3fbacf92c03566e8ffea5fdefd2d"
12:58:06 INFO - }
12:58:06 INFO - }
12:58:06 INFO - Found installer url https://queue.taskcluster.net/v1/task/WsFfSGx8Qu2guP2wehmoyw/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2.
12:58:06 INFO - Running post-action listener: _resource_record_post_action
12:58:06 INFO - #####
12:58:06 INFO - ##### Running download-and-extract step.
12:58:06 INFO - #####
12:58:06 INFO - Running pre-action listener: _resource_record_pre_action
12:58:06 INFO - Running main action method: download_and_extract
12:58:06 INFO - mkdir: /builds/slave/test/build/tests
12:58:06 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')]}
12:58:06 INFO - https://queue.taskcluster.net/v1/task/WsFfSGx8Qu2guP2wehmoyw/artifacts/public/build/test_packages.json matches https://queue.taskcluster.net
12:58:06 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/WsFfSGx8Qu2guP2wehmoyw/artifacts/public/build/test_packages.json
12:58:06 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/WsFfSGx8Qu2guP2wehmoyw/artifacts/public/build/test_packages.json
12:58:06 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/WsFfSGx8Qu2guP2wehmoyw/artifacts/public/build/test_packages.json to /builds/slave/test/build/test_packages.json
12:58:06 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/WsFfSGx8Qu2guP2wehmoyw/artifacts/public/build/test_packages.json', 'file_name': '/builds/slave/test/build/test_packages.json'}, attempt #1
12:58:06 INFO - Downloaded 1302 bytes.
12:58:06 INFO - Reading from file /builds/slave/test/build/test_packages.json
12:58:06 INFO - Using the following test package requirements:
12:58:06 INFO - {u'common': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'],
12:58:06 INFO - u'cppunittest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
12:58:06 INFO - u'firefox-45.0a1.en-US.linux-x86_64.cppunittest.tests.zip'],
12:58:06 INFO - u'jittest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
12:58:06 INFO - u'jsshell-linux-x86_64.zip'],
12:58:06 INFO - u'mochitest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
12:58:06 INFO - u'firefox-45.0a1.en-US.linux-x86_64.mochitest.tests.zip'],
12:58:06 INFO - u'mozbase': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'],
12:58:06 INFO - u'reftest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
12:58:06 INFO - u'firefox-45.0a1.en-US.linux-x86_64.reftest.tests.zip'],
12:58:06 INFO - u'talos': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
12:58:06 INFO - u'firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip'],
12:58:06 INFO - u'web-platform': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
12:58:06 INFO - u'firefox-45.0a1.en-US.linux-x86_64.web-platform.tests.zip'],
12:58:06 INFO - u'webapprt': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'],
12:58:06 INFO - u'xpcshell': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
12:58:06 INFO - u'firefox-45.0a1.en-US.linux-x86_64.xpcshell.tests.zip']}
12:58:06 INFO - Downloading packages: [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'] for test suite category: common
12:58:06 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')]}
12:58:06 INFO - https://queue.taskcluster.net/v1/task/WsFfSGx8Qu2guP2wehmoyw/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip matches https://queue.taskcluster.net
12:58:06 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/WsFfSGx8Qu2guP2wehmoyw/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
12:58:06 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/WsFfSGx8Qu2guP2wehmoyw/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
12:58:06 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/WsFfSGx8Qu2guP2wehmoyw/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
12:58:06 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/WsFfSGx8Qu2guP2wehmoyw/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
12:58:08 INFO - Downloaded 21340916 bytes.
12:58:08 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
12:58:08 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
12:58:08 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
12:58:09 INFO - Return code: 0
12:58:09 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
12:58: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')]}
12:58:09 INFO - https://queue.taskcluster.net/v1/task/WsFfSGx8Qu2guP2wehmoyw/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip matches https://queue.taskcluster.net
12:58:09 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/WsFfSGx8Qu2guP2wehmoyw/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
12:58:09 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/WsFfSGx8Qu2guP2wehmoyw/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
12:58:09 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/WsFfSGx8Qu2guP2wehmoyw/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
12:58:09 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/WsFfSGx8Qu2guP2wehmoyw/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
12:58:10 INFO - Downloaded 21340916 bytes.
12:58:10 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
12:58:10 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
12:58:10 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
12:58:11 INFO - Return code: 0
12:58:11 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
12:58:11 INFO - https://queue.taskcluster.net/v1/task/WsFfSGx8Qu2guP2wehmoyw/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip matches https://queue.taskcluster.net
12:58:11 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/WsFfSGx8Qu2guP2wehmoyw/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip
12:58:11 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/WsFfSGx8Qu2guP2wehmoyw/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip
12:58:11 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/WsFfSGx8Qu2guP2wehmoyw/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
12:58:11 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/WsFfSGx8Qu2guP2wehmoyw/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
12:58:12 INFO - Downloaded 11130997 bytes.
12:58:12 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
12:58:12 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip
12:58:12 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
12:58:12 INFO - Return code: 0
12:58: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')]}
12:58:12 INFO - https://queue.taskcluster.net/v1/task/WsFfSGx8Qu2guP2wehmoyw/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 matches https://queue.taskcluster.net
12:58:12 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/WsFfSGx8Qu2guP2wehmoyw/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2
12:58:12 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/WsFfSGx8Qu2guP2wehmoyw/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2
12:58:12 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/WsFfSGx8Qu2guP2wehmoyw/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
12:58:12 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/WsFfSGx8Qu2guP2wehmoyw/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
12:58:14 INFO - Downloaded 55781739 bytes.
12:58:14 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/WsFfSGx8Qu2guP2wehmoyw/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2
12:58:14 INFO - mkdir: /builds/slave/test/properties
12:58:14 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url
12:58:14 INFO - Writing to file /builds/slave/test/properties/build_url
12:58:14 INFO - Contents:
12:58:14 INFO - build_url:https://queue.taskcluster.net/v1/task/WsFfSGx8Qu2guP2wehmoyw/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2
12:58:14 INFO - Running post-action listener: _resource_record_post_action
12:58:14 INFO - Running post-action listener: set_extra_try_arguments
12:58:14 INFO - #####
12:58:14 INFO - ##### Running populate-webroot step.
12:58:14 INFO - #####
12:58:14 INFO - Running pre-action listener: _resource_record_pre_action
12:58:14 INFO - Running main action method: populate_webroot
12:58:14 INFO - {'extra_options': {'android': ['--apkPath=%(apk_path)s']},
12:58:14 INFO - 'mobile-suites': {'remote-tp4m_nochrome': {'tests': ['tp4m']},
12:58:14 INFO - 'remote-trobocheck2': {'talos_options': ['--fennecIDs',
12:58:14 INFO - '../fennec_ids.txt'],
12:58:14 INFO - 'tests': ['tcheck2']},
12:58:14 INFO - 'remote-tsvgx': {'talos_options': ['--noChrome',
12:58:14 INFO - '--tppagecycles',
12:58:14 INFO - '7'],
12:58:14 INFO - 'tests': ['tsvgm']}},
12:58:14 INFO - 'suites': {'chromez': {'tests': ['tresize', 'tcanvasmark']},
12:58:14 INFO - 'chromez-e10s': {'talos_options': ['--e10s'],
12:58:14 INFO - 'tests': ['tresize', 'tcanvasmark']},
12:58:14 INFO - 'dromaeojs': {'tests': ['dromaeo_css', 'kraken', 'v8_7']},
12:58:14 INFO - 'dromaeojs-e10s': {'talos_options': ['--e10s'],
12:58:14 INFO - 'tests': ['dromaeo_css', 'kraken', 'v8_7']},
12:58:14 INFO - 'g1': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
12:58:14 INFO - 'tests': ['tp5o_scroll', 'glterrain']},
12:58:14 INFO - 'g1-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
12:58:14 INFO - 'talos_options': ['--e10s'],
12:58:14 INFO - 'tests': ['tp5o_scroll', 'glterrain']},
12:58:14 INFO - 'g2': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
12:58:14 INFO - 'tests': ['damp', 'tps']},
12:58:14 INFO - 'g2-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
12:58:14 INFO - 'talos_options': ['--e10s'],
12:58:14 INFO - 'tests': ['damp', 'tps']},
12:58:14 INFO - 'g3': {'tests': ['dromaeo_dom']},
12:58:14 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']},
12:58:14 INFO - 'other': {'tests': ['a11yr',
12:58:14 INFO - 'ts_paint',
12:58:14 INFO - 'tpaint',
12:58:14 INFO - 'sessionrestore',
12:58:14 INFO - 'sessionrestore_no_auto_restore']},
12:58:14 INFO - 'other-e10s': {'talos_options': ['--e10s'],
12:58:14 INFO - 'tests': ['a11yr',
12:58:14 INFO - 'ts_paint',
12:58:14 INFO - 'tpaint',
12:58:14 INFO - 'sessionrestore',
12:58:14 INFO - 'sessionrestore_no_auto_restore']},
12:58:14 INFO - 'other-e10s_l64': {'talos_options': ['--e10s'],
12:58:14 INFO - 'tests': ['a11yr',
12:58:14 INFO - 'ts_paint',
12:58:14 INFO - 'tpaint',
12:58:14 INFO - 'sessionrestore',
12:58:14 INFO - 'sessionrestore_no_auto_restore']},
12:58:14 INFO - 'other-e10s_nol64': {'talos_options': ['--e10s'],
12:58:14 INFO - 'tests': ['a11yr',
12:58:14 INFO - 'ts_paint',
12:58:14 INFO - 'tpaint',
12:58:14 INFO - 'sessionrestore',
12:58:14 INFO - 'sessionrestore_no_auto_restore']},
12:58:14 INFO - 'other_l64': {'tests': ['a11yr',
12:58:14 INFO - 'ts_paint',
12:58:14 INFO - 'tpaint',
12:58:14 INFO - 'sessionrestore',
12:58:14 INFO - 'sessionrestore_no_auto_restore']},
12:58:14 INFO - 'other_nol64': {'tests': ['a11yr',
12:58:14 INFO - 'ts_paint',
12:58:14 INFO - 'tpaint',
12:58:14 INFO - 'sessionrestore',
12:58:14 INFO - 'sessionrestore_no_auto_restore']},
12:58:14 INFO - 'svgr': {'tests': ['tsvgx',
12:58:14 INFO - 'tsvgr_opacity',
12:58:14 INFO - 'tart',
12:58:14 INFO - 'tscrollx',
12:58:14 INFO - 'cart']},
12:58:14 INFO - 'svgr-e10s': {'talos_options': ['--e10s'],
12:58:14 INFO - 'tests': ['tsvgx',
12:58:14 INFO - 'tsvgr_opacity',
12:58:14 INFO - 'tart',
12:58:14 INFO - 'tscrollx',
12:58:14 INFO - 'cart']},
12:58:14 INFO - 'tp5o': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
12:58:14 INFO - 'tests': ['tp5o']},
12:58:14 INFO - 'tp5o-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
12:58:14 INFO - 'talos_options': ['--e10s'],
12:58:14 INFO - 'tests': ['tp5o']},
12:58:14 INFO - 'xperf': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
12:58:14 INFO - 'talos_options': ['--xperf_path',
12:58:14 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'],
12:58:14 INFO - 'tests': ['tp5n']},
12:58:14 INFO - 'xperf-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
12:58:14 INFO - 'talos_options': ['--e10s',
12:58:14 INFO - '--xperf_path',
12:58:14 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'],
12:58:14 INFO - 'tests': ['tp5n']}},
12:58:14 INFO - 'talos.zip': {'path': '',
12:58:14 INFO - 'url': 'http://talos-bundles.pvt.build.mozilla.org/zips/talos.a6052c33d420.zip'}}
12:58:14 INFO - Running post-action listener: _resource_record_post_action
12:58:14 INFO - #####
12:58:14 INFO - ##### Running create-virtualenv step.
12:58:14 INFO - #####
12:58:14 INFO - Running pre-action listener: _resource_record_pre_action
12:58:14 INFO - Running main action method: create_virtualenv
12:58:14 INFO - Creating virtualenv /builds/slave/test/build/venv
12:58:14 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
12:58:14 INFO - Copy/paste: /tools/buildbot/bin/python /tools/misc-python/virtualenv.py --no-site-packages --distribute /builds/slave/test/build/venv
12:58:14 INFO - The --no-site-packages flag is deprecated; it is now the default behavior.
12:58:14 INFO - Using real prefix '/usr'
12:58:14 INFO - New python executable in /builds/slave/test/build/venv/bin/python
12:58:15 INFO - Installing distribute.............................................................................................................................................................................................done.
12:58:17 INFO - Installing pip.................done.
12:58:17 INFO - Return code: 0
12:58:17 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv
12:58:17 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
12:58:17 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
12:58:17 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
12:58:17 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
12:58:17 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
12:58:17 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
12:58:17 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'pip>=1.5']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7f84b3729c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x25906c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2641900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2687b70>, '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 0x26d8dc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x26d9250>, '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': '919420d7ee4ef147bef0346300000385-1448312283.868710-972446830', '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
12:58:17 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'pip>=1.5'] in /builds/slave/test/build
12:58:17 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub pip>=1.5
12:58:17 INFO - Using env: {'DISPLAY': ':0',
12:58:17 INFO - 'HOME': '/home/cltbld',
12:58:17 INFO - 'LANG': 'en_US.UTF-8',
12:58:17 INFO - 'LANGUAGE': 'en_US:en',
12:58:17 INFO - 'LOGNAME': 'cltbld',
12:58:17 INFO - 'MAIL': '/var/mail/cltbld',
12:58:17 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
12:58:17 INFO - 'MOZ_NO_REMOTE': '1',
12:58:17 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
12:58:17 INFO - 'NO_EM_RESTART': '1',
12:58:17 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
12:58:17 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
12:58:17 INFO - 'PWD': '/builds/slave/test',
12:58:17 INFO - 'SHELL': '/bin/bash',
12:58:17 INFO - 'SHLVL': '1',
12:58:17 INFO - 'TERM': 'linux',
12:58:17 INFO - 'TMOUT': '86400',
12:58:17 INFO - 'USER': 'cltbld',
12:58:17 INFO - 'XDG_SESSION_COOKIE': '919420d7ee4ef147bef0346300000385-1448312283.868710-972446830',
12:58:17 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
12:58:17 INFO - '_': '/tools/buildbot/bin/python'}
12:58:17 INFO - Ignoring indexes: https://pypi.python.org/simple/
12:58:17 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
12:58:17 INFO - Cleaning up...
12:58:17 INFO - Return code: 0
12:58:17 INFO - Installing psutil>=0.7.1 into virtualenv /builds/slave/test/build/venv
12:58:17 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
12:58:17 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
12:58:17 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
12:58:17 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
12:58:17 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
12:58:17 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
12:58:17 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '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 0x7f84b3729c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x25906c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2641900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2687b70>, '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 0x26d8dc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x26d9250>, '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': '919420d7ee4ef147bef0346300000385-1448312283.868710-972446830', '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
12:58:17 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'psutil>=0.7.1'] in /builds/slave/test/build
12:58:17 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub psutil>=0.7.1
12:58:17 INFO - Using env: {'DISPLAY': ':0',
12:58:17 INFO - 'HOME': '/home/cltbld',
12:58:17 INFO - 'LANG': 'en_US.UTF-8',
12:58:17 INFO - 'LANGUAGE': 'en_US:en',
12:58:17 INFO - 'LOGNAME': 'cltbld',
12:58:17 INFO - 'MAIL': '/var/mail/cltbld',
12:58:17 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
12:58:17 INFO - 'MOZ_NO_REMOTE': '1',
12:58:17 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
12:58:17 INFO - 'NO_EM_RESTART': '1',
12:58:17 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
12:58:17 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
12:58:17 INFO - 'PWD': '/builds/slave/test',
12:58:17 INFO - 'SHELL': '/bin/bash',
12:58:17 INFO - 'SHLVL': '1',
12:58:17 INFO - 'TERM': 'linux',
12:58:17 INFO - 'TMOUT': '86400',
12:58:17 INFO - 'USER': 'cltbld',
12:58:17 INFO - 'XDG_SESSION_COOKIE': '919420d7ee4ef147bef0346300000385-1448312283.868710-972446830',
12:58:17 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
12:58:17 INFO - '_': '/tools/buildbot/bin/python'}
12:58:17 INFO - Ignoring indexes: https://pypi.python.org/simple/
12:58:17 INFO - Downloading/unpacking psutil>=0.7.1
12:58: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
12:58: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
12:58: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
12:58: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
12:58: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
12:58: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
12:58:19 INFO - Creating supposed download cache at /builds/slave/test/build/venv/cache
12:58:19 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fpsutil-3.1.1.tar.gz
12:58:19 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/psutil/setup.py) egg_info for package psutil
12:58:19 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build'
12:58:19 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects
...
12:58:19 INFO - Installing collected packages: psutil
12:58:19 INFO - Running setup.py install for psutil
12:58:19 INFO - building 'psutil._psutil_linux' extension
12:58:19 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
12:58:19 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
12:58:19 INFO - building 'psutil._psutil_posix' extension
12:58:19 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
12:58:20 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
12:58:20 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build'
12:58:20 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ...
12:58:20 INFO - Successfully installed psutil
12:58:20 INFO - Cleaning up...
12:58:20 INFO - Return code: 0
12:58:20 INFO - Installing mozsystemmonitor==0.0.0 into virtualenv /builds/slave/test/build/venv
12:58:20 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
12:58:20 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
12:58:20 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
12:58:20 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
12:58:20 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
12:58:20 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
12:58:20 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '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 0x7f84b3729c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x25906c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2641900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2687b70>, '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 0x26d8dc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x26d9250>, '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': '919420d7ee4ef147bef0346300000385-1448312283.868710-972446830', '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
12:58:20 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'mozsystemmonitor==0.0.0'] in /builds/slave/test/build
12:58:20 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub mozsystemmonitor==0.0.0
12:58:20 INFO - Using env: {'DISPLAY': ':0',
12:58:20 INFO - 'HOME': '/home/cltbld',
12:58:20 INFO - 'LANG': 'en_US.UTF-8',
12:58:20 INFO - 'LANGUAGE': 'en_US:en',
12:58:20 INFO - 'LOGNAME': 'cltbld',
12:58:20 INFO - 'MAIL': '/var/mail/cltbld',
12:58:20 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
12:58:20 INFO - 'MOZ_NO_REMOTE': '1',
12:58:20 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
12:58:20 INFO - 'NO_EM_RESTART': '1',
12:58:20 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
12:58:20 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
12:58:20 INFO - 'PWD': '/builds/slave/test',
12:58:20 INFO - 'SHELL': '/bin/bash',
12:58:20 INFO - 'SHLVL': '1',
12:58:20 INFO - 'TERM': 'linux',
12:58:20 INFO - 'TMOUT': '86400',
12:58:20 INFO - 'USER': 'cltbld',
12:58:20 INFO - 'XDG_SESSION_COOKIE': '919420d7ee4ef147bef0346300000385-1448312283.868710-972446830',
12:58:20 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
12:58:20 INFO - '_': '/tools/buildbot/bin/python'}
12:58:20 INFO - Ignoring indexes: https://pypi.python.org/simple/
12:58:20 INFO - Downloading/unpacking mozsystemmonitor==0.0.0
12:58:20 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
12:58:20 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
12:58:20 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
12:58:20 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
12:58:20 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
12:58:20 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
12:58:22 INFO - Downloading mozsystemmonitor-0.0.tar.gz
12:58:22 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fmozsystemmonitor-0.0.tar.gz
12:58:22 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/mozsystemmonitor/setup.py) egg_info for package mozsystemmonitor
12:58:22 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=0.7.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.0.0)
12:58:22 INFO - Installing collected packages: mozsystemmonitor
12:58:22 INFO - Running setup.py install for mozsystemmonitor
12:58:22 INFO - Successfully installed mozsystemmonitor
12:58:22 INFO - Cleaning up...
12:58:22 INFO - Return code: 0
12:58:22 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv
12:58:22 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')]}
12:58:22 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
12:58:22 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
12:58:22 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')]}
12:58:22 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
12:58:22 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
12:58:22 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 0x7f84b3729c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x25906c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2641900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2687b70>, '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 0x26d8dc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x26d9250>, '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': '919420d7ee4ef147bef0346300000385-1448312283.868710-972446830', '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
12:58:22 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
12:58:22 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
12:58:22 INFO - Using env: {'DISPLAY': ':0',
12:58:22 INFO - 'HOME': '/home/cltbld',
12:58:22 INFO - 'LANG': 'en_US.UTF-8',
12:58:22 INFO - 'LANGUAGE': 'en_US:en',
12:58:22 INFO - 'LOGNAME': 'cltbld',
12:58:22 INFO - 'MAIL': '/var/mail/cltbld',
12:58:22 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
12:58:22 INFO - 'MOZ_NO_REMOTE': '1',
12:58:22 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
12:58:22 INFO - 'NO_EM_RESTART': '1',
12:58:22 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
12:58:22 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
12:58:22 INFO - 'PWD': '/builds/slave/test',
12:58:22 INFO - 'SHELL': '/bin/bash',
12:58:22 INFO - 'SHLVL': '1',
12:58:22 INFO - 'TERM': 'linux',
12:58:22 INFO - 'TMOUT': '86400',
12:58:22 INFO - 'USER': 'cltbld',
12:58:22 INFO - 'XDG_SESSION_COOKIE': '919420d7ee4ef147bef0346300000385-1448312283.868710-972446830',
12:58:22 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
12:58:22 INFO - '_': '/tools/buildbot/bin/python'}
12:58:22 INFO - Ignoring indexes: https://pypi.python.org/simple/
12:58:22 INFO - Downloading/unpacking blobuploader==1.2.4
12:58:22 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
12:58:22 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
12:58:22 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
12:58:22 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
12:58:22 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
12:58:22 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
12:58:24 INFO - Downloading blobuploader-1.2.4.tar.gz
12:58:24 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fblobuploader-1.2.4.tar.gz
12:58:24 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blobuploader/setup.py) egg_info for package blobuploader
12:58:24 INFO - Downloading/unpacking requests==1.2.3. (from blobuploader==1.2.4)
12:58:24 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available
12:58:24 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available
12:58:24 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available
12:58:24 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available
12:58:24 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available
12:58:24 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available
12:58:24 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Frequests-1.2.3.tar.gz
12:58:24 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests
12:58:24 INFO - Downloading/unpacking docopt==0.6.1 (from blobuploader==1.2.4)
12:58:24 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available
12:58:24 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available
12:58:24 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available
12:58:24 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available
12:58:24 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available
12:58:24 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available
12:58:24 INFO - Downloading docopt-0.6.1.tar.gz
12:58:24 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fdocopt-0.6.1.tar.gz
12:58:24 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/docopt/setup.py) egg_info for package docopt
12:58:24 INFO - Installing collected packages: blobuploader, requests, docopt
12:58:24 INFO - Running setup.py install for blobuploader
12:58:24 INFO - changing mode of build/scripts-2.7/blobberc.py from 664 to 775
12:58:24 INFO - changing mode of /builds/slave/test/build/venv/bin/blobberc.py to 775
12:58:24 INFO - Running setup.py install for requests
12:58:25 INFO - Running setup.py install for docopt
12:58:25 INFO - Successfully installed blobuploader requests docopt
12:58:25 INFO - Cleaning up...
12:58:25 INFO - Return code: 0
12:58:25 INFO - Installing None into virtualenv /builds/slave/test/build/venv
12:58:25 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
12:58:25 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
12:58:25 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
12:58:25 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
12:58:25 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
12:58:25 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
12:58:25 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7f84b3729c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x25906c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2641900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2687b70>, '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 0x26d8dc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x26d9250>, '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': '919420d7ee4ef147bef0346300000385-1448312283.868710-972446830', '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
12:58:25 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/config
12:58:25 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --no-deps --download-cache /builds/slave/test/build/venv/cache --timeout 120 -r /builds/slave/test/build/tests/config/mozbase_requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub
12:58:25 INFO - Using env: {'DISPLAY': ':0',
12:58:25 INFO - 'HOME': '/home/cltbld',
12:58:25 INFO - 'LANG': 'en_US.UTF-8',
12:58:25 INFO - 'LANGUAGE': 'en_US:en',
12:58:25 INFO - 'LOGNAME': 'cltbld',
12:58:25 INFO - 'MAIL': '/var/mail/cltbld',
12:58:25 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
12:58:25 INFO - 'MOZ_NO_REMOTE': '1',
12:58:25 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
12:58:25 INFO - 'NO_EM_RESTART': '1',
12:58:25 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
12:58:25 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
12:58:25 INFO - 'PWD': '/builds/slave/test',
12:58:25 INFO - 'SHELL': '/bin/bash',
12:58:25 INFO - 'SHLVL': '1',
12:58:25 INFO - 'TERM': 'linux',
12:58:25 INFO - 'TMOUT': '86400',
12:58:25 INFO - 'USER': 'cltbld',
12:58:25 INFO - 'XDG_SESSION_COOKIE': '919420d7ee4ef147bef0346300000385-1448312283.868710-972446830',
12:58:25 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
12:58:25 INFO - '_': '/tools/buildbot/bin/python'}
12:58:25 INFO - Ignoring indexes: https://pypi.python.org/simple/
12:58:25 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser
12:58:25 INFO - Running setup.py (path:/tmp/pip-r0mHMm-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser
12:58:25 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash
12:58:25 INFO - Running setup.py (path:/tmp/pip-3v9Wgz-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash
12:58:25 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug
12:58:25 INFO - Running setup.py (path:/tmp/pip-jYTpGI-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug
12:58:25 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice
12:58:25 INFO - Running setup.py (path:/tmp/pip-uyTEkr-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice
12:58:25 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile
12:58:25 INFO - Running setup.py (path:/tmp/pip-gglXI4-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile
12:58:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd
12:58:26 INFO - Running setup.py (path:/tmp/pip-QqaTL4-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd
12:58:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo
12:58:26 INFO - Running setup.py (path:/tmp/pip-nG9j09-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo
12:58:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall
12:58:26 INFO - Running setup.py (path:/tmp/pip-VR6hyr-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall
12:58:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak
12:58:26 INFO - Running setup.py (path:/tmp/pip-LROeCc-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak
12:58:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog
12:58:26 INFO - Running setup.py (path:/tmp/pip-lL2WAj-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog
12:58:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork
12:58:26 INFO - Running setup.py (path:/tmp/pip-veK8Y2-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork
12:58:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess
12:58:26 INFO - Running setup.py (path:/tmp/pip-CpZXaT-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess
12:58:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile
12:58:26 INFO - Running setup.py (path:/tmp/pip-hPuqnd-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile
12:58:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner
12:58:26 INFO - Running setup.py (path:/tmp/pip-C4KwNJ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner
12:58:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot
12:58:26 INFO - Running setup.py (path:/tmp/pip-S2YJ6l-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot
12:58:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest
12:58:26 INFO - Running setup.py (path:/tmp/pip-BpsFH9-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest
12:58:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion
12:58:26 INFO - Running setup.py (path:/tmp/pip-RMs4Nm-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion
12:58:26 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion
12:58:26 INFO - Running setup.py install for manifestparser
12:58:26 INFO - Installing manifestparser script to /builds/slave/test/build/venv/bin
12:58:26 INFO - Running setup.py install for mozcrash
12:58:27 INFO - Running setup.py install for mozdebug
12:58:27 INFO - Running setup.py install for mozdevice
12:58:27 INFO - Installing sutini script to /builds/slave/test/build/venv/bin
12:58:27 INFO - Installing dm script to /builds/slave/test/build/venv/bin
12:58:27 INFO - Running setup.py install for mozfile
12:58:27 INFO - Running setup.py install for mozhttpd
12:58:27 INFO - Installing mozhttpd script to /builds/slave/test/build/venv/bin
12:58:27 INFO - Running setup.py install for mozinfo
12:58:27 INFO - Installing mozinfo script to /builds/slave/test/build/venv/bin
12:58:27 INFO - Running setup.py install for mozInstall
12:58:27 INFO - Installing moz_remove_from_system script to /builds/slave/test/build/venv/bin
12:58:27 INFO - Installing mozuninstall script to /builds/slave/test/build/venv/bin
12:58:27 INFO - Installing mozinstall script to /builds/slave/test/build/venv/bin
12:58:27 INFO - Installing moz_add_to_system script to /builds/slave/test/build/venv/bin
12:58:27 INFO - Running setup.py install for mozleak
12:58:27 INFO - Running setup.py install for mozlog
12:58:27 INFO - Installing structlog script to /builds/slave/test/build/venv/bin
12:58:27 INFO - Running setup.py install for moznetwork
12:58:27 INFO - Installing moznetwork script to /builds/slave/test/build/venv/bin
12:58:27 INFO - Running setup.py install for mozprocess
12:58:28 INFO - Running setup.py install for mozprofile
12:58:28 INFO - Installing mozprofile script to /builds/slave/test/build/venv/bin
12:58:28 INFO - Installing diff-profiles script to /builds/slave/test/build/venv/bin
12:58:28 INFO - Installing view-profile script to /builds/slave/test/build/venv/bin
12:58:28 INFO - Running setup.py install for mozrunner
12:58:28 INFO - Installing mozrunner script to /builds/slave/test/build/venv/bin
12:58:28 INFO - Running setup.py install for mozscreenshot
12:58:28 INFO - Running setup.py install for moztest
12:58:28 INFO - Running setup.py install for mozversion
12:58:28 INFO - Installing mozversion script to /builds/slave/test/build/venv/bin
12:58:28 INFO - Successfully installed manifestparser mozcrash mozdebug mozdevice mozfile mozhttpd mozinfo mozInstall mozleak mozlog moznetwork mozprocess mozprofile mozrunner mozscreenshot moztest mozversion
12:58:28 INFO - Cleaning up...
12:58:28 INFO - Return code: 0
12:58:28 INFO - Installing None into virtualenv /builds/slave/test/build/venv
12:58:28 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')]}
12:58:28 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
12:58:28 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
12:58:28 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')]}
12:58:28 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
12:58:28 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
12:58:28 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 0x7f84b3729c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x25906c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2641900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2687b70>, '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 0x26d8dc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x26d9250>, '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': '919420d7ee4ef147bef0346300000385-1448312283.868710-972446830', '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
12:58:28 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
12:58:28 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
12:58:28 INFO - Using env: {'DISPLAY': ':0',
12:58:28 INFO - 'HOME': '/home/cltbld',
12:58:28 INFO - 'LANG': 'en_US.UTF-8',
12:58:28 INFO - 'LANGUAGE': 'en_US:en',
12:58:28 INFO - 'LOGNAME': 'cltbld',
12:58:28 INFO - 'MAIL': '/var/mail/cltbld',
12:58:28 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
12:58:28 INFO - 'MOZ_NO_REMOTE': '1',
12:58:28 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
12:58:28 INFO - 'NO_EM_RESTART': '1',
12:58:28 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
12:58:28 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
12:58:28 INFO - 'PWD': '/builds/slave/test',
12:58:28 INFO - 'SHELL': '/bin/bash',
12:58:28 INFO - 'SHLVL': '1',
12:58:28 INFO - 'TERM': 'linux',
12:58:28 INFO - 'TMOUT': '86400',
12:58:28 INFO - 'USER': 'cltbld',
12:58:28 INFO - 'XDG_SESSION_COOKIE': '919420d7ee4ef147bef0346300000385-1448312283.868710-972446830',
12:58:28 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
12:58:28 INFO - '_': '/tools/buildbot/bin/python'}
12:58:28 INFO - Ignoring indexes: https://pypi.python.org/simple/
12:58:28 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser
12:58:28 INFO - Running setup.py (path:/tmp/pip-G0_DfQ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser
12:58:28 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))
12:58:28 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash
12:58:28 INFO - Running setup.py (path:/tmp/pip-U8UAiq-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash
12:58:29 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))
12:58:29 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug
12:58:29 INFO - Running setup.py (path:/tmp/pip-gUot64-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug
12:58:29 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))
12:58:29 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice
12:58:29 INFO - Running setup.py (path:/tmp/pip-64Pj4h-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice
12:58:29 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))
12:58:29 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile
12:58:29 INFO - Running setup.py (path:/tmp/pip-WiCpfs-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile
12:58:29 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))
12:58:29 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd
12:58:29 INFO - Running setup.py (path:/tmp/pip-EsAPzE-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd
12:58:29 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))
12:58:29 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo
12:58:29 INFO - Running setup.py (path:/tmp/pip-FSMQWp-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo
12:58:29 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))
12:58:29 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall
12:58:29 INFO - Running setup.py (path:/tmp/pip-I8RS8t-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall
12:58:29 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))
12:58:29 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak
12:58:29 INFO - Running setup.py (path:/tmp/pip-mV4yn7-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak
12:58:29 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))
12:58:29 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog
12:58:29 INFO - Running setup.py (path:/tmp/pip-3sACmD-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog
12:58:29 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))
12:58:29 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork
12:58:29 INFO - Running setup.py (path:/tmp/pip-h3QFH3-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork
12:58:29 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))
12:58:29 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess
12:58:29 INFO - Running setup.py (path:/tmp/pip-QHkTrF-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess
12:58:29 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))
12:58:29 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile
12:58:29 INFO - Running setup.py (path:/tmp/pip-5elCq3-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile
12:58:29 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))
12:58:29 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner
12:58:29 INFO - Running setup.py (path:/tmp/pip-vduA6f-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner
12:58:29 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))
12:58:29 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot
12:58:29 INFO - Running setup.py (path:/tmp/pip-S1a7OV-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot
12:58:29 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))
12:58:29 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest
12:58:29 INFO - Running setup.py (path:/tmp/pip-tAudoN-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest
12:58:29 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))
12:58:29 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion
12:58:29 INFO - Running setup.py (path:/tmp/pip-l68UME-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion
12:58:30 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))
12:58:30 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))
12:58:30 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))
12:58:30 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))
12:58:30 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))
12:58:30 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))
12:58:30 INFO - Downloading/unpacking blessings>=1.3 (from mozlog==3.0->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10))
12:58:30 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
12:58:30 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
12:58:30 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
12:58:30 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
12:58:30 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
12:58:30 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
12:58:31 INFO - Downloading blessings-1.5.1.tar.gz
12:58:31 INFO - Storing download in cache at /builds/slave/test/build/venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fblessings-1.5.1.tar.gz
12:58:31 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blessings/setup.py) egg_info for package blessings
12:58:31 INFO - Installing collected packages: blessings
12:58:31 INFO - Running setup.py install for blessings
12:58:31 INFO - Successfully installed blessings
12:58:31 INFO - Cleaning up...
12:58:31 INFO - Return code: 0
12:58:31 INFO - Done creating virtualenv /builds/slave/test/build/venv.
12:58:31 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze']
12:58:31 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze
12:58:32 INFO - Reading from file tmpfile_stdout
12:58:32 INFO - Current package versions:
12:58:32 INFO - argparse == 1.2.1
12:58:32 INFO - blessings == 1.5.1
12:58:32 INFO - blobuploader == 1.2.4
12:58:32 INFO - docopt == 0.6.1
12:58:32 INFO - manifestparser == 1.1
12:58:32 INFO - mozInstall == 1.12
12:58:32 INFO - mozcrash == 0.16
12:58:32 INFO - mozdebug == 0.1
12:58:32 INFO - mozdevice == 0.47
12:58:32 INFO - mozfile == 1.2
12:58:32 INFO - mozhttpd == 0.7
12:58:32 INFO - mozinfo == 0.9
12:58:32 INFO - mozleak == 0.1
12:58:32 INFO - mozlog == 3.0
12:58:32 INFO - moznetwork == 0.27
12:58:32 INFO - mozprocess == 0.22
12:58:32 INFO - mozprofile == 0.27
12:58:32 INFO - mozrunner == 6.11
12:58:32 INFO - mozscreenshot == 0.1
12:58:32 INFO - mozsystemmonitor == 0.0
12:58:32 INFO - moztest == 0.7
12:58:32 INFO - mozversion == 1.4
12:58:32 INFO - psutil == 3.1.1
12:58:32 INFO - requests == 1.2.3
12:58:32 INFO - wsgiref == 0.1.2
12:58:32 INFO - Installing None into virtualenv /builds/slave/test/build/venv
12:58:32 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
12:58:32 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
12:58:32 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
12:58:32 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
12:58:32 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
12:58:32 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
12:58:32 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test/build/tests/talos/requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7f84b3729c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x25906c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2641900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2687b70>, '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 0x26d8dc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x26d9250>, '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': '919420d7ee4ef147bef0346300000385-1448312283.868710-972446830', '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
12:58:32 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test/build/tests/talos/requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/talos
12:58:32 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 -r /builds/slave/test/build/tests/talos/requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub
12:58:32 INFO - Using env: {'DISPLAY': ':0',
12:58:32 INFO - 'HOME': '/home/cltbld',
12:58:32 INFO - 'LANG': 'en_US.UTF-8',
12:58:32 INFO - 'LANGUAGE': 'en_US:en',
12:58:32 INFO - 'LOGNAME': 'cltbld',
12:58:32 INFO - 'MAIL': '/var/mail/cltbld',
12:58:32 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
12:58:32 INFO - 'MOZ_NO_REMOTE': '1',
12:58:32 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
12:58:32 INFO - 'NO_EM_RESTART': '1',
12:58:32 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
12:58:32 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
12:58:32 INFO - 'PWD': '/builds/slave/test',
12:58:32 INFO - 'SHELL': '/bin/bash',
12:58:32 INFO - 'SHLVL': '1',
12:58:32 INFO - 'TERM': 'linux',
12:58:32 INFO - 'TMOUT': '86400',
12:58:32 INFO - 'USER': 'cltbld',
12:58:32 INFO - 'XDG_SESSION_COOKIE': '919420d7ee4ef147bef0346300000385-1448312283.868710-972446830',
12:58:32 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
12:58:32 INFO - '_': '/tools/buildbot/bin/python'}
12:58:32 INFO - Ignoring indexes: https://pypi.python.org/simple/
12:58:32 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash>=0.15 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 1))
12:58:32 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.2 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 2))
12:58:32 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd>=0.7 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 3))
12:58:32 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo>=0.8 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 4))
12:58:32 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.22 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 5))
12:58:32 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion>=1.3 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 6))
12:58:32 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile>=0.25 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 7))
12:58:32 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 8))
12:58:32 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozcrash>=0.15->-r /builds/slave/test/build/tests/talos/requirements.txt (line 1))
12:58:32 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork>=0.24 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozhttpd>=0.7->-r /builds/slave/test/build/tests/talos/requirements.txt (line 3))
12:58:32 INFO - Requirement already satisfied (use --upgrade to upgrade): blessings>=1.3 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozlog>=3.0->mozcrash>=0.15->-r /builds/slave/test/build/tests/talos/requirements.txt (line 1))
12:58:32 INFO - Cleaning up...
12:58:32 INFO - Return code: 0
12:58:32 INFO - Running post-action listener: _resource_record_post_action
12:58:32 INFO - Running post-action listener: _start_resource_monitoring
12:58:32 INFO - Starting resource monitoring.
12:58:32 INFO - #####
12:58:32 INFO - ##### Running install step.
12:58:32 INFO - #####
12:58:32 INFO - Running pre-action listener: _resource_record_pre_action
12:58:32 INFO - Running main action method: install
12:58:32 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze']
12:58:32 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze
12:58:32 INFO - Reading from file tmpfile_stdout
12:58:32 INFO - Detecting whether we're running mozinstall >=1.0...
12:58:32 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h']
12:58:32 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h
12:58:32 INFO - Reading from file tmpfile_stdout
12:58:32 INFO - Output received:
12:58:32 INFO - Usage: mozinstall [options] installer
12:58:32 INFO - Options:
12:58:32 INFO - -h, --help show this help message and exit
12:58:32 INFO - -d DEST, --destination=DEST
12:58:32 INFO - Directory to install application into. [default:
12:58:32 INFO - "/builds/slave/test"]
12:58:32 INFO - --app=APP Application being installed. [default: firefox]
12:58:32 INFO - mkdir: /builds/slave/test/build/application
12:58:32 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']
12:58:32 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
12:58:46 INFO - Reading from file tmpfile_stdout
12:58:46 INFO - Output received:
12:58:46 INFO - /builds/slave/test/build/application/firefox/firefox
12:58:46 INFO - Running post-action listener: _resource_record_post_action
12:58:46 INFO - #####
12:58:46 INFO - ##### Running run-tests step.
12:58:46 INFO - #####
12:58:46 INFO - Running pre-action listener: _resource_record_pre_action
12:58:46 INFO - Running main action method: run_tests
12:58:46 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version']
12:58:46 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version
12:58:46 INFO - Python 2.7.3
12:58:46 INFO - Return code: 0
12:58:46 INFO - grabbing minidump binary from tooltool
12:58:46 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
12:58:46 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 0x2687b70>, '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 0x26d8dc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x26d9250>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1
12:58:46 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
12:58:46 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
12:58:46 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache
12:58:46 INFO - Return code: 0
12:58:46 INFO - Chmoding /builds/slave/test/build/linux64-minidump_stackwalk to 0755
12:58:46 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir
12:58:46 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir
12:58:46 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/linux64-minidump_stackwalk
12:58:46 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir
12:58:46 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/WsFfSGx8Qu2guP2wehmoyw/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-053', '--webServer', 'localhost'] in /builds/slave/test/build
12:58:46 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/WsFfSGx8Qu2guP2wehmoyw/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.crashreporter-symbols.zip --title talos-linux64-ix-053 --webServer localhost
12:58:46 INFO - Using env: {'DISPLAY': ':0',
12:58:46 INFO - 'HOME': '/home/cltbld',
12:58:46 INFO - 'LANG': 'en_US.UTF-8',
12:58:46 INFO - 'LANGUAGE': 'en_US:en',
12:58:46 INFO - 'LOGNAME': 'cltbld',
12:58:46 INFO - 'MAIL': '/var/mail/cltbld',
12:58:46 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir',
12:58:46 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk',
12:58:46 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
12:58:46 INFO - 'MOZ_NO_REMOTE': '1',
12:58:46 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir',
12:58:46 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
12:58:46 INFO - 'NO_EM_RESTART': '1',
12:58:46 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
12:58:46 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
12:58:46 INFO - 'PWD': '/builds/slave/test',
12:58:46 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos',
12:58:46 INFO - 'SHELL': '/bin/bash',
12:58:46 INFO - 'SHLVL': '1',
12:58:46 INFO - 'TERM': 'linux',
12:58:46 INFO - 'TMOUT': '86400',
12:58:46 INFO - 'USER': 'cltbld',
12:58:46 INFO - 'XDG_SESSION_COOKIE': '919420d7ee4ef147bef0346300000385-1448312283.868710-972446830',
12:58:46 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
12:58:46 INFO - '_': '/tools/buildbot/bin/python'}
12:58:46 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/WsFfSGx8Qu2guP2wehmoyw/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-053', '--webServer', 'localhost'] with output_timeout 3600
12:58:47 INFO - mozversion INFO | application_buildid: 20151120090830
12:58:47 INFO - mozversion INFO | application_changeset: a0db720c980e3fbacf92c03566e8ffea5fdefd2d
12:58:47 INFO - mozversion INFO | application_display_name: Nightly
12:58:47 INFO - mozversion INFO | application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384}
12:58:47 INFO - mozversion INFO | application_name: Firefox
12:58:47 INFO - mozversion INFO | application_remotingname: firefox
12:58:47 INFO - mozversion INFO | application_repository: https://hg.mozilla.org/integration/fx-team
12:58:47 INFO - mozversion INFO | application_vendor: Mozilla
12:58:47 INFO - mozversion INFO | application_version: 45.0a1
12:58:47 INFO - mozversion INFO | platform_buildid: 20151120090830
12:58:47 INFO - mozversion INFO | platform_changeset: a0db720c980e3fbacf92c03566e8ffea5fdefd2d
12:58:47 INFO - mozversion INFO | platform_repository: https://hg.mozilla.org/integration/fx-team
12:58:47 INFO - mozversion INFO | platform_version: 45.0a1
12:58:47 INFO - 2015-11-23 12:58:47,071 DEBUG : using testdate: 1448312327
12:58:47 INFO - 2015-11-23 12:58:47,071 DEBUG : actual date: 1448312327
12:58:47 INFO - 2015-11-23 12:58:47,079 INFO : starting webserver on 'localhost:53751'
12:58:47 INFO - 2015-11-23 12:58:47,080 INFO : Starting test suite talos-linux64-ix-053.e
12:58:47 INFO - 2015-11-23 12:58:47,080 INFO : Starting test a11yr
12:58:47 INFO - 2015-11-23 12:58:47,080 DEBUG : operating with platform_type : linux_
12:58:47 INFO - 2015-11-23 12:58:47,081 INFO : Initialising browser for a11yr test...
12:58:47 INFO - 2015-11-23 12:58:47,095 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpIv2Rcr/profile http://localhost:53751/getInfo.html
12:58:51 INFO - 2015-11-23 12:58:51,416 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
12:58:51 INFO - 2015-11-23 12:58:51,416 DEBUG : BROWSER_OUTPUT: colorDepth:24
12:58:51 INFO - 2015-11-23 12:58:51,416 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697
12:58:51 INFO - 2015-11-23 12:58:51,416 DEBUG : BROWSER_OUTPUT: __metrics
12:58:52 INFO - 2015-11-23 12:58:52,493 INFO : Browser initialized.
12:58:52 INFO - 2015-11-23 12:58:52,494 INFO : Running cycle 1/1 for a11yr test...
12:58:52 INFO - 2015-11-23 12:58:52,494 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpIv2Rcr/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/a11y/a11y.manifest.develop -tpchrome -tpmozafterpaint -tpnoisy -tpcycles 1 -tppagecycles 25
12:59:04 INFO - 2015-11-23 12:59:04,427 DEBUG : BROWSER_OUTPUT: RSS: Main: 141611008
12:59:04 INFO - 2015-11-23 12:59:04,427 DEBUG : BROWSER_OUTPUT:
12:59:05 INFO - 2015-11-23 12:59:05,696 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)
12:59:05 INFO - 2015-11-23 12:59:05,837 DEBUG : BROWSER_OUTPUT:
12:59:05 INFO - 2015-11-23 12:59:05,837 DEBUG : BROWSER_OUTPUT: (firefox:2478): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed
12:59:05 INFO - 2015-11-23 12:59:05,837 DEBUG : BROWSER_OUTPUT:
12:59:05 INFO - 2015-11-23 12:59:05,837 DEBUG : BROWSER_OUTPUT: (firefox:2478): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed
12:59:05 INFO - 2015-11-23 12:59:05,898 DEBUG : BROWSER_OUTPUT:
12:59:05 INFO - 2015-11-23 12:59:05,898 DEBUG : BROWSER_OUTPUT: (firefox:2478): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed
12:59:06 INFO - 2015-11-23 12:59:06,329 DEBUG : BROWSER_OUTPUT: RSS: Main: 146583552
12:59:06 INFO - 2015-11-23 12:59:06,329 DEBUG : BROWSER_OUTPUT:
12:59:07 INFO - 2015-11-23 12:59:07,725 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)
12:59:08 INFO - 2015-11-23 12:59:08,427 DEBUG : BROWSER_OUTPUT: RSS: Main: 145776640
12:59:08 INFO - 2015-11-23 12:59:08,427 DEBUG : BROWSER_OUTPUT:
12:59:09 INFO - 2015-11-23 12:59:09,771 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)
12:59:10 INFO - 2015-11-23 12:59:10,473 DEBUG : BROWSER_OUTPUT: RSS: Main: 144707584
12:59:10 INFO - 2015-11-23 12:59:10,473 DEBUG : BROWSER_OUTPUT:
12:59:11 INFO - 2015-11-23 12:59:11,843 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)
12:59:12 INFO - 2015-11-23 12:59:12,537 DEBUG : BROWSER_OUTPUT: RSS: Main: 144879616
12:59:12 INFO - 2015-11-23 12:59:12,537 DEBUG : BROWSER_OUTPUT:
12:59:13 INFO - 2015-11-23 12:59:13,933 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)
12:59:14 INFO - 2015-11-23 12:59:14,639 DEBUG : BROWSER_OUTPUT: RSS: Main: 142012416
12:59:14 INFO - 2015-11-23 12:59:14,640 DEBUG : BROWSER_OUTPUT:
12:59:15 INFO - 2015-11-23 12:59:15,996 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)
12:59:16 INFO - 2015-11-23 12:59:16,702 DEBUG : BROWSER_OUTPUT: RSS: Main: 142000128
12:59:16 INFO - 2015-11-23 12:59:16,703 DEBUG : BROWSER_OUTPUT:
12:59:18 INFO - 2015-11-23 12:59:18,098 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)
12:59:18 INFO - 2015-11-23 12:59:18,805 DEBUG : BROWSER_OUTPUT: RSS: Main: 142180352
12:59:18 INFO - 2015-11-23 12:59:18,805 DEBUG : BROWSER_OUTPUT:
12:59:20 INFO - 2015-11-23 12:59:20,195 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)
12:59:20 INFO - 2015-11-23 12:59:20,898 DEBUG : BROWSER_OUTPUT: RSS: Main: 141864960
12:59:20 INFO - 2015-11-23 12:59:20,898 DEBUG : BROWSER_OUTPUT:
12:59:22 INFO - 2015-11-23 12:59:22,262 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)
12:59:22 INFO - 2015-11-23 12:59:22,963 DEBUG : BROWSER_OUTPUT: RSS: Main: 141971456
12:59:22 INFO - 2015-11-23 12:59:22,963 DEBUG : BROWSER_OUTPUT:
12:59:24 INFO - 2015-11-23 12:59:24,339 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)
12:59:25 INFO - 2015-11-23 12:59:25,041 DEBUG : BROWSER_OUTPUT: RSS: Main: 142151680
12:59:25 INFO - 2015-11-23 12:59:25,041 DEBUG : BROWSER_OUTPUT:
12:59:26 INFO - 2015-11-23 12:59:26,413 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)
12:59:27 INFO - 2015-11-23 12:59:27,114 DEBUG : BROWSER_OUTPUT: RSS: Main: 141922304
12:59:27 INFO - 2015-11-23 12:59:27,114 DEBUG : BROWSER_OUTPUT:
12:59:28 INFO - 2015-11-23 12:59:28,498 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)
12:59:29 INFO - 2015-11-23 12:59:29,208 DEBUG : BROWSER_OUTPUT: RSS: Main: 142737408
12:59:29 INFO - 2015-11-23 12:59:29,208 DEBUG : BROWSER_OUTPUT:
12:59:30 INFO - 2015-11-23 12:59:30,556 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)
12:59:31 INFO - 2015-11-23 12:59:31,267 DEBUG : BROWSER_OUTPUT: RSS: Main: 142409728
12:59:31 INFO - 2015-11-23 12:59:31,267 DEBUG : BROWSER_OUTPUT:
12:59:32 INFO - 2015-11-23 12:59:32,631 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)
12:59:33 INFO - 2015-11-23 12:59:33,332 DEBUG : BROWSER_OUTPUT: RSS: Main: 142225408
12:59:33 INFO - 2015-11-23 12:59:33,332 DEBUG : BROWSER_OUTPUT:
12:59:34 INFO - 2015-11-23 12:59:34,716 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)
12:59:35 INFO - 2015-11-23 12:59:35,478 DEBUG : BROWSER_OUTPUT: RSS: Main: 141697024
12:59:35 INFO - 2015-11-23 12:59:35,479 DEBUG : BROWSER_OUTPUT:
12:59:36 INFO - 2015-11-23 12:59:36,829 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)
12:59:37 INFO - 2015-11-23 12:59:37,530 DEBUG : BROWSER_OUTPUT: RSS: Main: 143818752
12:59:37 INFO - 2015-11-23 12:59:37,531 DEBUG : BROWSER_OUTPUT:
12:59:38 INFO - 2015-11-23 12:59:38,899 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)
12:59:39 INFO - 2015-11-23 12:59:39,601 DEBUG : BROWSER_OUTPUT: RSS: Main: 143937536
12:59:39 INFO - 2015-11-23 12:59:39,601 DEBUG : BROWSER_OUTPUT:
12:59:40 INFO - 2015-11-23 12:59:40,991 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)
12:59:41 INFO - 2015-11-23 12:59:41,704 DEBUG : BROWSER_OUTPUT: RSS: Main: 143896576
12:59:41 INFO - 2015-11-23 12:59:41,705 DEBUG : BROWSER_OUTPUT:
12:59:43 INFO - 2015-11-23 12:59:43,089 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)
12:59:43 INFO - 2015-11-23 12:59:43,783 DEBUG : BROWSER_OUTPUT: RSS: Main: 143699968
12:59:43 INFO - 2015-11-23 12:59:43,783 DEBUG : BROWSER_OUTPUT:
12:59:45 INFO - 2015-11-23 12:59:45,147 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)
12:59:45 INFO - 2015-11-23 12:59:45,848 DEBUG : BROWSER_OUTPUT: RSS: Main: 143716352
12:59:45 INFO - 2015-11-23 12:59:45,849 DEBUG : BROWSER_OUTPUT:
12:59:47 INFO - 2015-11-23 12:59:47,420 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)
12:59:48 INFO - 2015-11-23 12:59:48,127 DEBUG : BROWSER_OUTPUT: RSS: Main: 143757312
12:59:48 INFO - 2015-11-23 12:59:48,127 DEBUG : BROWSER_OUTPUT:
12:59:49 INFO - 2015-11-23 12:59:49,511 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)
12:59:50 INFO - 2015-11-23 12:59:50,217 DEBUG : BROWSER_OUTPUT: RSS: Main: 143855616
12:59:50 INFO - 2015-11-23 12:59:50,218 DEBUG : BROWSER_OUTPUT:
12:59:51 INFO - 2015-11-23 12:59:51,602 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)
12:59:52 INFO - 2015-11-23 12:59:52,304 DEBUG : BROWSER_OUTPUT: RSS: Main: 142450688
12:59:52 INFO - 2015-11-23 12:59:52,304 DEBUG : BROWSER_OUTPUT:
12:59:53 INFO - 2015-11-23 12:59:53,709 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)
12:59:54 INFO - 2015-11-23 12:59:54,093 DEBUG : BROWSER_OUTPUT: 1448312394089 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]
12:59:54 INFO - 2015-11-23 12:59:54,443 DEBUG : BROWSER_OUTPUT: RSS: Main: 151007232
12:59:54 INFO - 2015-11-23 12:59:54,443 DEBUG : BROWSER_OUTPUT:
12:59:56 INFO - 2015-11-23 12:59:56,050 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)
12:59:56 INFO - 2015-11-23 12:59:56,778 DEBUG : BROWSER_OUTPUT: RSS: Main: 156987392
12:59:56 INFO - 2015-11-23 12:59:56,778 DEBUG : BROWSER_OUTPUT:
12:59:57 INFO - 2015-11-23 12:59:57,176 DEBUG : BROWSER_OUTPUT:
12:59:57 INFO - 2015-11-23 12:59:57,176 DEBUG : BROWSER_OUTPUT: (firefox:2478): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed
12:59:57 INFO - 2015-11-23 12:59:57,781 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)
12:59:58 INFO - 2015-11-23 12:59:58,370 DEBUG : BROWSER_OUTPUT: RSS: Main: 152449024
12:59:58 INFO - 2015-11-23 12:59:58,370 DEBUG : BROWSER_OUTPUT:
12:59:59 INFO - 2015-11-23 12:59:59,296 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)
12:59:59 INFO - 2015-11-23 12:59:59,902 DEBUG : BROWSER_OUTPUT: RSS: Main: 151150592
12:59:59 INFO - 2015-11-23 12:59:59,902 DEBUG : BROWSER_OUTPUT:
13:00:00 INFO - 2015-11-23 13:00:00,824 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)
13:00:01 INFO - 2015-11-23 13:00:01,430 DEBUG : BROWSER_OUTPUT: RSS: Main: 149970944
13:00:01 INFO - 2015-11-23 13:00:01,430 DEBUG : BROWSER_OUTPUT:
13:00:02 INFO - 2015-11-23 13:00:02,351 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)
13:00:02 INFO - 2015-11-23 13:00:02,953 DEBUG : BROWSER_OUTPUT: RSS: Main: 148819968
13:00:02 INFO - 2015-11-23 13:00:02,953 DEBUG : BROWSER_OUTPUT:
13:00:03 INFO - 2015-11-23 13:00:03,874 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)
13:00:04 INFO - 2015-11-23 13:00:04,476 DEBUG : BROWSER_OUTPUT: RSS: Main: 142741504
13:00:04 INFO - 2015-11-23 13:00:04,476 DEBUG : BROWSER_OUTPUT:
13:00:05 INFO - 2015-11-23 13:00:05,422 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)
13:00:06 INFO - 2015-11-23 13:00:06,024 DEBUG : BROWSER_OUTPUT: RSS: Main: 140627968
13:00:06 INFO - 2015-11-23 13:00:06,024 DEBUG : BROWSER_OUTPUT:
13:00:06 INFO - 2015-11-23 13:00:06,945 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)
13:00:07 INFO - 2015-11-23 13:00:07,551 DEBUG : BROWSER_OUTPUT: RSS: Main: 140419072
13:00:07 INFO - 2015-11-23 13:00:07,551 DEBUG : BROWSER_OUTPUT:
13:00:08 INFO - 2015-11-23 13:00:08,485 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)
13:00:09 INFO - 2015-11-23 13:00:09,086 DEBUG : BROWSER_OUTPUT: RSS: Main: 141279232
13:00:09 INFO - 2015-11-23 13:00:09,087 DEBUG : BROWSER_OUTPUT:
13:00:09 INFO - 2015-11-23 13:00:09,993 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)
13:00:10 INFO - 2015-11-23 13:00:10,594 DEBUG : BROWSER_OUTPUT: RSS: Main: 139538432
13:00:10 INFO - 2015-11-23 13:00:10,594 DEBUG : BROWSER_OUTPUT:
13:00:11 INFO - 2015-11-23 13:00:11,516 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)
13:00:12 INFO - 2015-11-23 13:00:12,119 DEBUG : BROWSER_OUTPUT: RSS: Main: 139526144
13:00:12 INFO - 2015-11-23 13:00:12,119 DEBUG : BROWSER_OUTPUT:
13:00:13 INFO - 2015-11-23 13:00:13,041 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)
13:00:13 INFO - 2015-11-23 13:00:13,642 DEBUG : BROWSER_OUTPUT: RSS: Main: 139599872
13:00:13 INFO - 2015-11-23 13:00:13,642 DEBUG : BROWSER_OUTPUT:
13:00:14 INFO - 2015-11-23 13:00:14,570 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)
13:00:15 INFO - 2015-11-23 13:00:15,171 DEBUG : BROWSER_OUTPUT: RSS: Main: 141209600
13:00:15 INFO - 2015-11-23 13:00:15,171 DEBUG : BROWSER_OUTPUT:
13:00:16 INFO - 2015-11-23 13:00:16,093 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)
13:00:16 INFO - 2015-11-23 13:00:16,694 DEBUG : BROWSER_OUTPUT: RSS: Main: 139300864
13:00:16 INFO - 2015-11-23 13:00:16,694 DEBUG : BROWSER_OUTPUT:
13:00:17 INFO - 2015-11-23 13:00:17,636 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)
13:00:18 INFO - 2015-11-23 13:00:18,237 DEBUG : BROWSER_OUTPUT: RSS: Main: 141520896
13:00:18 INFO - 2015-11-23 13:00:18,238 DEBUG : BROWSER_OUTPUT:
13:00:19 INFO - 2015-11-23 13:00:19,159 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)
13:00:19 INFO - 2015-11-23 13:00:19,765 DEBUG : BROWSER_OUTPUT: RSS: Main: 139350016
13:00:19 INFO - 2015-11-23 13:00:19,765 DEBUG : BROWSER_OUTPUT:
13:00:20 INFO - 2015-11-23 13:00:20,699 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)
13:00:21 INFO - 2015-11-23 13:00:21,300 DEBUG : BROWSER_OUTPUT: RSS: Main: 139149312
13:00:21 INFO - 2015-11-23 13:00:21,300 DEBUG : BROWSER_OUTPUT:
13:00:22 INFO - 2015-11-23 13:00:22,227 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)
13:00:22 INFO - 2015-11-23 13:00:22,828 DEBUG : BROWSER_OUTPUT: RSS: Main: 140292096
13:00:22 INFO - 2015-11-23 13:00:22,828 DEBUG : BROWSER_OUTPUT:
13:00:23 INFO - 2015-11-23 13:00:23,741 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)
13:00:24 INFO - 2015-11-23 13:00:24,355 DEBUG : BROWSER_OUTPUT: RSS: Main: 141094912
13:00:24 INFO - 2015-11-23 13:00:24,355 DEBUG : BROWSER_OUTPUT:
13:00:25 INFO - 2015-11-23 13:00:25,277 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)
13:00:25 INFO - 2015-11-23 13:00:25,883 DEBUG : BROWSER_OUTPUT: RSS: Main: 142278656
13:00:25 INFO - 2015-11-23 13:00:25,883 DEBUG : BROWSER_OUTPUT:
13:00:26 INFO - 2015-11-23 13:00:26,817 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)
13:00:27 INFO - 2015-11-23 13:00:27,418 DEBUG : BROWSER_OUTPUT: RSS: Main: 142295040
13:00:27 INFO - 2015-11-23 13:00:27,418 DEBUG : BROWSER_OUTPUT:
13:00:28 INFO - 2015-11-23 13:00:28,327 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)
13:00:28 INFO - 2015-11-23 13:00:28,933 DEBUG : BROWSER_OUTPUT: RSS: Main: 140144640
13:00:28 INFO - 2015-11-23 13:00:28,933 DEBUG : BROWSER_OUTPUT:
13:00:29 INFO - 2015-11-23 13:00:29,846 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)
13:00:30 INFO - 2015-11-23 13:00:30,448 DEBUG : BROWSER_OUTPUT: RSS: Main: 142516224
13:00:30 INFO - 2015-11-23 13:00:30,448 DEBUG : BROWSER_OUTPUT:
13:00:31 INFO - 2015-11-23 13:00:31,390 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)
13:00:31 INFO - 2015-11-23 13:00:31,997 DEBUG : BROWSER_OUTPUT: RSS: Main: 140259328
13:00:31 INFO - 2015-11-23 13:00:31,998 DEBUG : BROWSER_OUTPUT:
13:00:32 INFO - 2015-11-23 13:00:32,924 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)
13:00:33 INFO - 2015-11-23 13:00:33,530 DEBUG : BROWSER_OUTPUT: RSS: Main: 142139392
13:00:33 INFO - 2015-11-23 13:00:33,530 DEBUG : BROWSER_OUTPUT:
13:00:34 INFO - 2015-11-23 13:00:34,460 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)
13:00:34 INFO - 2015-11-23 13:00:34,710 DEBUG : BROWSER_OUTPUT: RSS: Main: 140910592
13:00:34 INFO - 2015-11-23 13:00:34,710 DEBUG : BROWSER_OUTPUT:
13:00:34 INFO - 2015-11-23 13:00:34,712 DEBUG : BROWSER_OUTPUT: __start_tp_report
13:00:34 INFO - 2015-11-23 13:00:34,712 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load
13:00:34 INFO - 2015-11-23 13:00:34,712 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load_details
13:00:34 INFO - 2015-11-23 13:00:34,712 DEBUG : BROWSER_OUTPUT: |i|pagename|runs|
13:00:34 INFO - 2015-11-23 13:00:34,712 DEBUG : BROWSER_OUTPUT: |0;dhtml.html;1243;1294;1291;1294;1312;1308;1317;1306;1299;1307;1309;1302;1302;1312;1310;1301;1298;1305;1303;1306;1524;1301;1305;1319;1550
13:00:34 INFO - 2015-11-23 13:00:34,712 DEBUG : BROWSER_OUTPUT: |1;tablemutation.html;379;382;395;386;388;394;383;384;374;385;380;393;388;385;376;385;391;379;393;376;381;386;387;387;384
13:00:34 INFO - 2015-11-23 13:00:34,712 DEBUG : BROWSER_OUTPUT: __end_tp_report
13:00:34 INFO - 2015-11-23 13:00:34,713 DEBUG : BROWSER_OUTPUT: __start_cc_report
13:00:34 INFO - 2015-11-23 13:00:34,713 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_cycle_collect,2801
13:00:34 INFO - 2015-11-23 13:00:34,713 DEBUG : BROWSER_OUTPUT: __end_cc_report
13:00:34 INFO - 2015-11-23 13:00:34,713 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312434710__endTimestamp
13:00:34 INFO - 2015-11-23 13:00:34,713 DEBUG : BROWSER_OUTPUT:
13:00:34 INFO - 2015-11-23 13:00:34,714 DEBUG : BROWSER_OUTPUT: ------- Summary: start -------
13:00:34 INFO - 2015-11-23 13:00:34,715 DEBUG : BROWSER_OUTPUT: Number of tests: 2
13:00:34 INFO - 2015-11-23 13:00:34,715 DEBUG : BROWSER_OUTPUT:
13:00:34 INFO - 2015-11-23 13:00:34,715 DEBUG : BROWSER_OUTPUT: [#0] dhtml.html Cycles:25 Average:1320.72 Median:1305.00 stddev:66.68 (5.1%) stddev-sans-first:66.08
13:00:34 INFO - 2015-11-23 13:00:34,715 DEBUG : BROWSER_OUTPUT: Values: 1243.0 1294.0 1291.0 1294.0 1312.0 1308.0 1317.0 1306.0 1299.0 1307.0 1309.0 1302.0 1302.0 1312.0 1310.0 1301.0 1298.0 1305.0 1303.0 1306.0 1524.0 1301.0 1305.0 1319.0 1550.0
13:00:34 INFO - 2015-11-23 13:00:34,715 DEBUG : BROWSER_OUTPUT:
13:00:34 INFO - 2015-11-23 13:00:34,715 DEBUG : BROWSER_OUTPUT: [#1] tablemutation.html Cycles:25 Average:384.84 Median:385.00 stddev:5.71 (1.5%) stddev-sans-first:5.70
13:00:34 INFO - 2015-11-23 13:00:34,715 DEBUG : BROWSER_OUTPUT: Values: 379.0 382.0 395.0 386.0 388.0 394.0 383.0 384.0 374.0 385.0 380.0 393.0 388.0 385.0 376.0 385.0 391.0 379.0 393.0 376.0 381.0 386.0 387.0 387.0 384.0
13:00:34 INFO - 2015-11-23 13:00:34,716 DEBUG : BROWSER_OUTPUT: -------- Summary: end --------
13:00:34 INFO - 2015-11-23 13:00:34,716 DEBUG : BROWSER_OUTPUT:
13:00:35 INFO - 2015-11-23 13:00:35,437 INFO : Browser exited with error code: 0
13:00:35 INFO - 2015-11-23 13:00:35,456 INFO : Completed test a11yr (00:01:48)
13:00:35 INFO - 2015-11-23 13:00:35,456 INFO : Starting test ts_paint
13:00:35 INFO - 2015-11-23 13:00:35,456 DEBUG : operating with platform_type : linux_
13:00:35 INFO - 2015-11-23 13:00:35,456 INFO : Initialising browser for ts_paint test...
13:00:35 INFO - 2015-11-23 13:00:35,462 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpqCJSBw/profile http://localhost:53751/getInfo.html
13:00:39 INFO - 2015-11-23 13:00:39,809 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
13:00:39 INFO - 2015-11-23 13:00:39,809 DEBUG : BROWSER_OUTPUT: colorDepth:24
13:00:39 INFO - 2015-11-23 13:00:39,809 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697
13:00:39 INFO - 2015-11-23 13:00:39,809 DEBUG : BROWSER_OUTPUT: __metrics
13:00:40 INFO - 2015-11-23 13:00:40,825 INFO : Browser initialized.
13:00:40 INFO - 2015-11-23 13:00:40,826 INFO : Running cycle 1/20 for ts_paint test...
13:00:40 INFO - 2015-11-23 13:00:40,826 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpqCJSBw/profile http://localhost:53751/startup_test/tspaint_test.html
13:00:42 INFO - 2015-11-23 13:00:42,969 DEBUG : BROWSER_OUTPUT: __start_report499__end_report
13:00:42 INFO - 2015-11-23 13:00:42,969 DEBUG : BROWSER_OUTPUT:
13:00:42 INFO - 2015-11-23 13:00:42,985 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312442980__endTimestamp
13:00:43 INFO - 2015-11-23 13:00:43,877 INFO : Browser exited with error code: 0
13:00:43 INFO - 2015-11-23 13:00:43,879 INFO : Running cycle 2/20 for ts_paint test...
13:00:43 INFO - 2015-11-23 13:00:43,879 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpqCJSBw/profile http://localhost:53751/startup_test/tspaint_test.html
13:00:45 INFO - 2015-11-23 13:00:45,472 DEBUG : BROWSER_OUTPUT: __start_report538__end_report
13:00:45 INFO - 2015-11-23 13:00:45,473 DEBUG : BROWSER_OUTPUT:
13:00:45 INFO - 2015-11-23 13:00:45,489 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312445481__endTimestamp
13:00:46 INFO - 2015-11-23 13:00:46,345 INFO : Browser exited with error code: 0
13:00:46 INFO - 2015-11-23 13:00:46,347 INFO : Running cycle 3/20 for ts_paint test...
13:00:46 INFO - 2015-11-23 13:00:46,347 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpqCJSBw/profile http://localhost:53751/startup_test/tspaint_test.html
13:00:48 INFO - 2015-11-23 13:00:48,025 DEBUG : BROWSER_OUTPUT: __start_report572__end_report
13:00:48 INFO - 2015-11-23 13:00:48,025 DEBUG : BROWSER_OUTPUT:
13:00:48 INFO - 2015-11-23 13:00:48,033 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312448030__endTimestamp
13:00:48 INFO - 2015-11-23 13:00:48,953 INFO : Browser exited with error code: 0
13:00:48 INFO - 2015-11-23 13:00:48,955 INFO : Running cycle 4/20 for ts_paint test...
13:00:48 INFO - 2015-11-23 13:00:48,955 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpqCJSBw/profile http://localhost:53751/startup_test/tspaint_test.html
13:00:50 INFO - 2015-11-23 13:00:50,597 DEBUG : BROWSER_OUTPUT: __start_report587__end_report
13:00:50 INFO - 2015-11-23 13:00:50,597 DEBUG : BROWSER_OUTPUT:
13:00:50 INFO - 2015-11-23 13:00:50,613 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312450606__endTimestamp
13:00:51 INFO - 2015-11-23 13:00:51,601 INFO : Browser exited with error code: 0
13:00:51 INFO - 2015-11-23 13:00:51,603 INFO : Running cycle 5/20 for ts_paint test...
13:00:51 INFO - 2015-11-23 13:00:51,603 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpqCJSBw/profile http://localhost:53751/startup_test/tspaint_test.html
13:00:53 INFO - 2015-11-23 13:00:53,200 DEBUG : BROWSER_OUTPUT: __start_report498__end_report
13:00:53 INFO - 2015-11-23 13:00:53,201 DEBUG : BROWSER_OUTPUT:
13:00:53 INFO - 2015-11-23 13:00:53,208 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312453206__endTimestamp
13:00:54 INFO - 2015-11-23 13:00:54,213 INFO : Browser exited with error code: 0
13:00:54 INFO - 2015-11-23 13:00:54,215 INFO : Running cycle 6/20 for ts_paint test...
13:00:54 INFO - 2015-11-23 13:00:54,215 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpqCJSBw/profile http://localhost:53751/startup_test/tspaint_test.html
13:00:55 INFO - 2015-11-23 13:00:55,897 DEBUG : BROWSER_OUTPUT: __start_report562__end_report
13:00:55 INFO - 2015-11-23 13:00:55,897 DEBUG : BROWSER_OUTPUT:
13:00:55 INFO - 2015-11-23 13:00:55,913 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312455907__endTimestamp
13:00:56 INFO - 2015-11-23 13:00:56,925 INFO : Browser exited with error code: 0
13:00:56 INFO - 2015-11-23 13:00:56,927 INFO : Running cycle 7/20 for ts_paint test...
13:00:56 INFO - 2015-11-23 13:00:56,927 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpqCJSBw/profile http://localhost:53751/startup_test/tspaint_test.html
13:00:58 INFO - 2015-11-23 13:00:58,540 DEBUG : BROWSER_OUTPUT: __start_report537__end_report
13:00:58 INFO - 2015-11-23 13:00:58,540 DEBUG : BROWSER_OUTPUT:
13:00:58 INFO - 2015-11-23 13:00:58,547 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312458544__endTimestamp
13:00:59 INFO - 2015-11-23 13:00:59,557 INFO : Browser exited with error code: 0
13:00:59 INFO - 2015-11-23 13:00:59,559 INFO : Running cycle 8/20 for ts_paint test...
13:00:59 INFO - 2015-11-23 13:00:59,559 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpqCJSBw/profile http://localhost:53751/startup_test/tspaint_test.html
13:01:01 INFO - 2015-11-23 13:01:01,143 DEBUG : BROWSER_OUTPUT: __start_report494__end_report
13:01:01 INFO - 2015-11-23 13:01:01,143 DEBUG : BROWSER_OUTPUT:
13:01:01 INFO - 2015-11-23 13:01:01,144 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312461144__endTimestamp
13:01:02 INFO - 2015-11-23 13:01:02,118 INFO : Browser exited with error code: 0
13:01:02 INFO - 2015-11-23 13:01:02,119 INFO : Running cycle 9/20 for ts_paint test...
13:01:02 INFO - 2015-11-23 13:01:02,119 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpqCJSBw/profile http://localhost:53751/startup_test/tspaint_test.html
13:01:03 INFO - 2015-11-23 13:01:03,751 DEBUG : BROWSER_OUTPUT: __start_report535__end_report
13:01:03 INFO - 2015-11-23 13:01:03,752 DEBUG : BROWSER_OUTPUT:
13:01:03 INFO - 2015-11-23 13:01:03,755 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312463754__endTimestamp
13:01:04 INFO - 2015-11-23 13:01:04,742 INFO : Browser exited with error code: 0
13:01:04 INFO - 2015-11-23 13:01:04,743 INFO : Running cycle 10/20 for ts_paint test...
13:01:04 INFO - 2015-11-23 13:01:04,743 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpqCJSBw/profile http://localhost:53751/startup_test/tspaint_test.html
13:01:06 INFO - 2015-11-23 13:01:06,355 DEBUG : BROWSER_OUTPUT: __start_report540__end_report
13:01:06 INFO - 2015-11-23 13:01:06,356 DEBUG : BROWSER_OUTPUT:
13:01:06 INFO - 2015-11-23 13:01:06,372 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312466366__endTimestamp
13:01:07 INFO - 2015-11-23 13:01:07,429 INFO : Browser exited with error code: 0
13:01:07 INFO - 2015-11-23 13:01:07,431 INFO : Running cycle 11/20 for ts_paint test...
13:01:07 INFO - 2015-11-23 13:01:07,431 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpqCJSBw/profile http://localhost:53751/startup_test/tspaint_test.html
13:01:09 INFO - 2015-11-23 13:01:09,016 DEBUG : BROWSER_OUTPUT: __start_report498__end_report
13:01:09 INFO - 2015-11-23 13:01:09,016 DEBUG : BROWSER_OUTPUT:
13:01:09 INFO - 2015-11-23 13:01:09,023 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312469022__endTimestamp
13:01:10 INFO - 2015-11-23 13:01:10,038 INFO : Browser exited with error code: 0
13:01:10 INFO - 2015-11-23 13:01:10,039 INFO : Running cycle 12/20 for ts_paint test...
13:01:10 INFO - 2015-11-23 13:01:10,039 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpqCJSBw/profile http://localhost:53751/startup_test/tspaint_test.html
13:01:11 INFO - 2015-11-23 13:01:11,592 DEBUG : BROWSER_OUTPUT: __start_report496__end_report
13:01:11 INFO - 2015-11-23 13:01:11,593 DEBUG : BROWSER_OUTPUT:
13:01:11 INFO - 2015-11-23 13:01:11,594 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312471593__endTimestamp
13:01:12 INFO - 2015-11-23 13:01:12,665 INFO : Browser exited with error code: 0
13:01:12 INFO - 2015-11-23 13:01:12,667 INFO : Running cycle 13/20 for ts_paint test...
13:01:12 INFO - 2015-11-23 13:01:12,667 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpqCJSBw/profile http://localhost:53751/startup_test/tspaint_test.html
13:01:14 INFO - 2015-11-23 13:01:14,225 DEBUG : BROWSER_OUTPUT: __start_report504__end_report
13:01:14 INFO - 2015-11-23 13:01:14,225 DEBUG : BROWSER_OUTPUT:
13:01:14 INFO - 2015-11-23 13:01:14,226 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312474226__endTimestamp
13:01:15 INFO - 2015-11-23 13:01:15,273 INFO : Browser exited with error code: 0
13:01:15 INFO - 2015-11-23 13:01:15,275 INFO : Running cycle 14/20 for ts_paint test...
13:01:15 INFO - 2015-11-23 13:01:15,275 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpqCJSBw/profile http://localhost:53751/startup_test/tspaint_test.html
13:01:16 INFO - 2015-11-23 13:01:16,853 DEBUG : BROWSER_OUTPUT: __start_report519__end_report
13:01:16 INFO - 2015-11-23 13:01:16,853 DEBUG : BROWSER_OUTPUT:
13:01:16 INFO - 2015-11-23 13:01:16,869 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312476864__endTimestamp
13:01:17 INFO - 2015-11-23 13:01:17,934 INFO : Browser exited with error code: 0
13:01:17 INFO - 2015-11-23 13:01:17,935 INFO : Running cycle 15/20 for ts_paint test...
13:01:17 INFO - 2015-11-23 13:01:17,935 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpqCJSBw/profile http://localhost:53751/startup_test/tspaint_test.html
13:01:19 INFO - 2015-11-23 13:01:19,513 DEBUG : BROWSER_OUTPUT: __start_report547__end_report
13:01:19 INFO - 2015-11-23 13:01:19,513 DEBUG : BROWSER_OUTPUT:
13:01:19 INFO - 2015-11-23 13:01:19,520 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312479519__endTimestamp
13:01:20 INFO - 2015-11-23 13:01:20,589 INFO : Browser exited with error code: 0
13:01:20 INFO - 2015-11-23 13:01:20,591 INFO : Running cycle 16/20 for ts_paint test...
13:01:20 INFO - 2015-11-23 13:01:20,591 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpqCJSBw/profile http://localhost:53751/startup_test/tspaint_test.html
13:01:22 INFO - 2015-11-23 13:01:22,207 DEBUG : BROWSER_OUTPUT: __start_report538__end_report
13:01:22 INFO - 2015-11-23 13:01:22,207 DEBUG : BROWSER_OUTPUT:
13:01:22 INFO - 2015-11-23 13:01:22,215 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312482212__endTimestamp
13:01:23 INFO - 2015-11-23 13:01:23,257 INFO : Browser exited with error code: 0
13:01:23 INFO - 2015-11-23 13:01:23,259 INFO : Running cycle 17/20 for ts_paint test...
13:01:23 INFO - 2015-11-23 13:01:23,259 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpqCJSBw/profile http://localhost:53751/startup_test/tspaint_test.html
13:01:24 INFO - 2015-11-23 13:01:24,856 DEBUG : BROWSER_OUTPUT: __start_report537__end_report
13:01:24 INFO - 2015-11-23 13:01:24,857 DEBUG : BROWSER_OUTPUT:
13:01:24 INFO - 2015-11-23 13:01:24,872 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312484865__endTimestamp
13:01:25 INFO - 2015-11-23 13:01:25,989 INFO : Browser exited with error code: 0
13:01:25 INFO - 2015-11-23 13:01:25,991 INFO : Running cycle 18/20 for ts_paint test...
13:01:25 INFO - 2015-11-23 13:01:25,991 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpqCJSBw/profile http://localhost:53751/startup_test/tspaint_test.html
13:01:27 INFO - 2015-11-23 13:01:27,611 DEBUG : BROWSER_OUTPUT: __start_report543__end_report
13:01:27 INFO - 2015-11-23 13:01:27,611 DEBUG : BROWSER_OUTPUT:
13:01:27 INFO - 2015-11-23 13:01:27,619 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312487618__endTimestamp
13:01:28 INFO - 2015-11-23 13:01:28,701 INFO : Browser exited with error code: 0
13:01:28 INFO - 2015-11-23 13:01:28,703 INFO : Running cycle 19/20 for ts_paint test...
13:01:28 INFO - 2015-11-23 13:01:28,703 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpqCJSBw/profile http://localhost:53751/startup_test/tspaint_test.html
13:01:30 INFO - 2015-11-23 13:01:30,337 DEBUG : BROWSER_OUTPUT: __start_report528__end_report
13:01:30 INFO - 2015-11-23 13:01:30,337 DEBUG : BROWSER_OUTPUT:
13:01:30 INFO - 2015-11-23 13:01:30,341 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312490340__endTimestamp
13:01:31 INFO - 2015-11-23 13:01:31,365 INFO : Browser exited with error code: 0
13:01:31 INFO - 2015-11-23 13:01:31,367 INFO : Running cycle 20/20 for ts_paint test...
13:01:31 INFO - 2015-11-23 13:01:31,367 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpqCJSBw/profile http://localhost:53751/startup_test/tspaint_test.html
13:01:32 INFO - 2015-11-23 13:01:32,991 DEBUG : BROWSER_OUTPUT: __start_report504__end_report
13:01:32 INFO - 2015-11-23 13:01:32,991 DEBUG : BROWSER_OUTPUT:
13:01:32 INFO - 2015-11-23 13:01:32,999 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312492997__endTimestamp
13:01:34 INFO - 2015-11-23 13:01:34,085 INFO : Browser exited with error code: 0
13:01:34 INFO - 2015-11-23 13:01:34,104 INFO : Completed test ts_paint (00:00:58)
13:01:34 INFO - 2015-11-23 13:01:34,104 INFO : Starting test tpaint
13:01:34 INFO - 2015-11-23 13:01:34,104 DEBUG : operating with platform_type : linux_
13:01:34 INFO - 2015-11-23 13:01:34,105 INFO : Initialising browser for tpaint test...
13:01:34 INFO - 2015-11-23 13:01:34,111 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpvm3TDY/profile http://localhost:53751/getInfo.html
13:01:38 INFO - 2015-11-23 13:01:38,317 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
13:01:38 INFO - 2015-11-23 13:01:38,317 DEBUG : BROWSER_OUTPUT: colorDepth:24
13:01:38 INFO - 2015-11-23 13:01:38,317 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697
13:01:38 INFO - 2015-11-23 13:01:38,317 DEBUG : BROWSER_OUTPUT: __metrics
13:01:39 INFO - 2015-11-23 13:01:39,265 INFO : Browser initialized.
13:01:39 INFO - 2015-11-23 13:01:39,266 INFO : Running cycle 1/1 for tpaint test...
13:01:39 INFO - 2015-11-23 13:01:39,266 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpvm3TDY/profile file:///builds/slave/test/build/tests/talos/talos/startup_test/tpaint.html?auto=1
13:02:07 INFO - 2015-11-23 13:02:07,441 DEBUG : BROWSER_OUTPUT: __start_report228.32500000000073|243.3050000000003|256.90499999999975|261.0749999999998|268.0100000000002|283.0750000000007|283.21000000000004|286.9250000000029|290.9549999999999|294.21500000000015|301.1949999999997|316.375|316.9900000000016|317.3250000000007|319.7649999999994|327.375|353.59999999999945|353.880000000001|379.15500000000065|411.71000000000095__end_report__startTimestamp1448312527436__endTimestamp
13:02:07 INFO - 2015-11-23 13:02:07,441 DEBUG : BROWSER_OUTPUT: openingTimes=243.3050000000003,256.90499999999975,261.0749999999998,268.0100000000002,283.0750000000007,283.21000000000004,286.9250000000029,290.9549999999999,294.21500000000015,301.1949999999997,316.375,316.9900000000016,317.3250000000007,319.7649999999994,327.375,353.59999999999945,353.880000000001,379.15500000000065,411.71000000000095
13:02:07 INFO - 2015-11-23 13:02:07,441 DEBUG : BROWSER_OUTPUT: avgOpenTime:304.67
13:02:07 INFO - 2015-11-23 13:02:07,441 DEBUG : BROWSER_OUTPUT: minOpenTime:228.33
13:02:07 INFO - 2015-11-23 13:02:07,442 DEBUG : BROWSER_OUTPUT: maxOpenTime:411.71
13:02:07 INFO - 2015-11-23 13:02:07,442 DEBUG : BROWSER_OUTPUT: medOpenTime:297.7049999999999
13:02:07 INFO - 2015-11-23 13:02:07,442 DEBUG : BROWSER_OUTPUT: __xulWinOpenTime:297.7049999999999
13:02:08 INFO - 2015-11-23 13:02:08,489 INFO : Browser exited with error code: 0
13:02:08 INFO - 2015-11-23 13:02:08,503 INFO : Completed test tpaint (00:00:34)
13:02:08 INFO - 2015-11-23 13:02:08,503 INFO : Starting test sessionrestore
13:02:08 INFO - 2015-11-23 13:02:08,503 DEBUG : operating with platform_type : linux_
13:02:08 INFO - 2015-11-23 13:02:08,503 INFO : Initialising browser for sessionrestore test...
13:02:08 INFO - 2015-11-23 13:02:08,513 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpwmMp9m/profile http://localhost:53751/getInfo.html
13:02:15 INFO - 2015-11-23 13:02:15,992 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
13:02:15 INFO - 2015-11-23 13:02:15,993 DEBUG : BROWSER_OUTPUT: colorDepth:24
13:02:15 INFO - 2015-11-23 13:02:15,993 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1151/811
13:02:15 INFO - 2015-11-23 13:02:15,993 DEBUG : BROWSER_OUTPUT: __metrics
13:02:16 ERROR - 2015-11-23 13:02:16,283 DEBUG : BROWSER_OUTPUT: JavaScript error: chrome://browser/content/browser.js, line 17078: TypeError: browser.permitUnload is not a function
13:02:16 ERROR - 2015-11-23 13:02:16,620 DEBUG : BROWSER_OUTPUT: JavaScript error: chrome://browser/content/browser.js, line 17078: TypeError: browser.permitUnload is not a function
13:02:17 INFO - 2015-11-23 13:02:17,641 INFO : Browser initialized.
13:02:17 INFO - 2015-11-23 13:02:17,642 INFO : Running cycle 1/10 for sessionrestore test...
13:02:17 INFO - 2015-11-23 13:02:17,642 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpwmMp9m/profile/sessionstore.js
13:02:17 INFO - 2015-11-23 13:02:17,644 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpwmMp9m/profile/sessionCheckpoints.json
13:02:17 INFO - 2015-11-23 13:02:17,645 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpwmMp9m/profile http://localhost:53751/startup_test/sessionrestore/index.html
13:02:23 INFO - 2015-11-23 13:02:23,373 DEBUG : BROWSER_OUTPUT: __start_report1476__end_report
13:02:23 INFO - 2015-11-23 13:02:23,374 DEBUG : BROWSER_OUTPUT:
13:02:23 INFO - 2015-11-23 13:02:23,374 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312543373__endTimestamp
13:02:23 INFO - 2015-11-23 13:02:23,374 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,150 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,150 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:24 INFO - 2015-11-23 13:02:24,150 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,151 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,151 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:24 INFO - 2015-11-23 13:02:24,151 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,151 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,151 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:24 INFO - 2015-11-23 13:02:24,151 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,151 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,151 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:24 INFO - 2015-11-23 13:02:24,151 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,152 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,152 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:24 INFO - 2015-11-23 13:02:24,152 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,152 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,152 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:24 INFO - 2015-11-23 13:02:24,152 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,152 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,152 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:24 INFO - 2015-11-23 13:02:24,152 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,152 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,153 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:24 INFO - 2015-11-23 13:02:24,153 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,153 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,153 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:24 INFO - 2015-11-23 13:02:24,153 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,153 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,153 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:24 INFO - 2015-11-23 13:02:24,153 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,153 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,154 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:24 INFO - 2015-11-23 13:02:24,154 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,154 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,154 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:24 INFO - 2015-11-23 13:02:24,154 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,154 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,154 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:24 INFO - 2015-11-23 13:02:24,154 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,154 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,154 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:24 INFO - 2015-11-23 13:02:24,155 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,155 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,155 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:24 INFO - 2015-11-23 13:02:24,155 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,155 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,155 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:24 INFO - 2015-11-23 13:02:24,155 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,155 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,155 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:24 INFO - 2015-11-23 13:02:24,155 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,156 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,156 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:24 INFO - 2015-11-23 13:02:24,156 DEBUG : BROWSER_OUTPUT:
13:02:24 INFO - 2015-11-23 13:02:24,897 INFO : Browser exited with error code: 0
13:02:24 INFO - 2015-11-23 13:02:24,899 INFO : Running cycle 2/10 for sessionrestore test...
13:02:24 INFO - 2015-11-23 13:02:24,899 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpwmMp9m/profile/sessionstore.js
13:02:24 INFO - 2015-11-23 13:02:24,901 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpwmMp9m/profile/sessionCheckpoints.json
13:02:24 INFO - 2015-11-23 13:02:24,902 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpwmMp9m/profile http://localhost:53751/startup_test/sessionrestore/index.html
13:02:29 INFO - 2015-11-23 13:02:29,858 DEBUG : BROWSER_OUTPUT: __start_report1171__end_report
13:02:29 INFO - 2015-11-23 13:02:29,858 DEBUG : BROWSER_OUTPUT:
13:02:29 INFO - 2015-11-23 13:02:29,858 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312549858__endTimestamp
13:02:29 INFO - 2015-11-23 13:02:29,858 DEBUG : BROWSER_OUTPUT:
13:02:30 INFO - 2015-11-23 13:02:30,586 DEBUG : BROWSER_OUTPUT: [Child 5715] 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
13:02:30 INFO - 2015-11-23 13:02:30,586 DEBUG : BROWSER_OUTPUT:
13:02:30 INFO - 2015-11-23 13:02:30,586 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:30 INFO - 2015-11-23 13:02:30,586 DEBUG : BROWSER_OUTPUT:
13:02:30 INFO - 2015-11-23 13:02:30,587 DEBUG : BROWSER_OUTPUT:
13:02:30 INFO - 2015-11-23 13:02:30,587 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:30 INFO - 2015-11-23 13:02:30,587 DEBUG : BROWSER_OUTPUT:
13:02:30 INFO - 2015-11-23 13:02:30,587 DEBUG : BROWSER_OUTPUT:
13:02:30 INFO - 2015-11-23 13:02:30,587 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:30 INFO - 2015-11-23 13:02:30,587 DEBUG : BROWSER_OUTPUT:
13:02:30 INFO - 2015-11-23 13:02:30,587 DEBUG : BROWSER_OUTPUT:
13:02:30 INFO - 2015-11-23 13:02:30,588 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:30 INFO - 2015-11-23 13:02:30,588 DEBUG : BROWSER_OUTPUT:
13:02:30 INFO - 2015-11-23 13:02:30,588 DEBUG : BROWSER_OUTPUT:
13:02:30 INFO - 2015-11-23 13:02:30,588 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:30 INFO - 2015-11-23 13:02:30,588 DEBUG : BROWSER_OUTPUT:
13:02:30 INFO - 2015-11-23 13:02:30,588 DEBUG : BROWSER_OUTPUT:
13:02:30 INFO - 2015-11-23 13:02:30,589 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:30 INFO - 2015-11-23 13:02:30,589 DEBUG : BROWSER_OUTPUT:
13:02:30 INFO - 2015-11-23 13:02:30,589 DEBUG : BROWSER_OUTPUT:
13:02:30 INFO - 2015-11-23 13:02:30,589 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:30 INFO - 2015-11-23 13:02:30,589 DEBUG : BROWSER_OUTPUT:
13:02:30 INFO - 2015-11-23 13:02:30,589 DEBUG : BROWSER_OUTPUT:
13:02:30 INFO - 2015-11-23 13:02:30,589 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:30 INFO - 2015-11-23 13:02:30,589 DEBUG : BROWSER_OUTPUT:
13:02:30 INFO - 2015-11-23 13:02:30,589 DEBUG : BROWSER_OUTPUT:
13:02:30 INFO - 2015-11-23 13:02:30,590 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:30 INFO - 2015-11-23 13:02:30,590 DEBUG : BROWSER_OUTPUT:
13:02:30 INFO - 2015-11-23 13:02:30,590 DEBUG : BROWSER_OUTPUT:
13:02:30 INFO - 2015-11-23 13:02:30,590 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:30 INFO - 2015-11-23 13:02:30,590 DEBUG : BROWSER_OUTPUT:
13:02:30 INFO - 2015-11-23 13:02:30,590 DEBUG : BROWSER_OUTPUT:
13:02:30 INFO - 2015-11-23 13:02:30,590 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:30 INFO - 2015-11-23 13:02:30,590 DEBUG : BROWSER_OUTPUT:
13:02:31 INFO - 2015-11-23 13:02:31,285 INFO : Browser exited with error code: 0
13:02:31 INFO - 2015-11-23 13:02:31,287 INFO : Running cycle 3/10 for sessionrestore test...
13:02:31 INFO - 2015-11-23 13:02:31,287 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpwmMp9m/profile/sessionstore.js
13:02:31 INFO - 2015-11-23 13:02:31,289 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpwmMp9m/profile/sessionCheckpoints.json
13:02:31 INFO - 2015-11-23 13:02:31,290 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpwmMp9m/profile http://localhost:53751/startup_test/sessionrestore/index.html
13:02:36 INFO - 2015-11-23 13:02:36,226 DEBUG : BROWSER_OUTPUT: __start_report1150__end_report
13:02:36 INFO - 2015-11-23 13:02:36,226 DEBUG : BROWSER_OUTPUT:
13:02:36 INFO - 2015-11-23 13:02:36,226 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312556224__endTimestamp
13:02:36 INFO - 2015-11-23 13:02:36,226 DEBUG : BROWSER_OUTPUT:
13:02:36 INFO - 2015-11-23 13:02:36,982 DEBUG : BROWSER_OUTPUT:
13:02:36 INFO - 2015-11-23 13:02:36,982 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:36 INFO - 2015-11-23 13:02:36,982 DEBUG : BROWSER_OUTPUT:
13:02:36 INFO - 2015-11-23 13:02:36,983 DEBUG : BROWSER_OUTPUT:
13:02:36 INFO - 2015-11-23 13:02:36,983 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:36 INFO - 2015-11-23 13:02:36,983 DEBUG : BROWSER_OUTPUT:
13:02:36 INFO - 2015-11-23 13:02:36,983 DEBUG : BROWSER_OUTPUT:
13:02:36 INFO - 2015-11-23 13:02:36,983 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:36 INFO - 2015-11-23 13:02:36,983 DEBUG : BROWSER_OUTPUT:
13:02:36 INFO - 2015-11-23 13:02:36,983 DEBUG : BROWSER_OUTPUT:
13:02:36 INFO - 2015-11-23 13:02:36,983 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:36 INFO - 2015-11-23 13:02:36,983 DEBUG : BROWSER_OUTPUT:
13:02:36 INFO - 2015-11-23 13:02:36,983 DEBUG : BROWSER_OUTPUT:
13:02:36 INFO - 2015-11-23 13:02:36,984 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:36 INFO - 2015-11-23 13:02:36,984 DEBUG : BROWSER_OUTPUT:
13:02:36 INFO - 2015-11-23 13:02:36,984 DEBUG : BROWSER_OUTPUT:
13:02:36 INFO - 2015-11-23 13:02:36,984 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:36 INFO - 2015-11-23 13:02:36,984 DEBUG : BROWSER_OUTPUT:
13:02:36 INFO - 2015-11-23 13:02:36,984 DEBUG : BROWSER_OUTPUT:
13:02:36 INFO - 2015-11-23 13:02:36,984 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:36 INFO - 2015-11-23 13:02:36,984 DEBUG : BROWSER_OUTPUT:
13:02:36 INFO - 2015-11-23 13:02:36,984 DEBUG : BROWSER_OUTPUT:
13:02:36 INFO - 2015-11-23 13:02:36,984 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:36 INFO - 2015-11-23 13:02:36,984 DEBUG : BROWSER_OUTPUT:
13:02:36 INFO - 2015-11-23 13:02:36,984 DEBUG : BROWSER_OUTPUT:
13:02:36 INFO - 2015-11-23 13:02:36,984 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:36 INFO - 2015-11-23 13:02:36,984 DEBUG : BROWSER_OUTPUT:
13:02:37 INFO - 2015-11-23 13:02:37,693 INFO : Browser exited with error code: 0
13:02:37 INFO - 2015-11-23 13:02:37,695 INFO : Running cycle 4/10 for sessionrestore test...
13:02:37 INFO - 2015-11-23 13:02:37,695 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpwmMp9m/profile/sessionstore.js
13:02:37 INFO - 2015-11-23 13:02:37,697 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpwmMp9m/profile/sessionCheckpoints.json
13:02:37 INFO - 2015-11-23 13:02:37,698 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpwmMp9m/profile http://localhost:53751/startup_test/sessionrestore/index.html
13:02:42 INFO - 2015-11-23 13:02:42,744 DEBUG : BROWSER_OUTPUT: __start_report1169__end_report
13:02:42 INFO - 2015-11-23 13:02:42,744 DEBUG : BROWSER_OUTPUT:
13:02:42 INFO - 2015-11-23 13:02:42,744 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312562744__endTimestamp
13:02:42 INFO - 2015-11-23 13:02:42,745 DEBUG : BROWSER_OUTPUT:
13:02:43 INFO - 2015-11-23 13:02:43,505 DEBUG : BROWSER_OUTPUT: [Child 5955] WARNING: pipe error: Broken pipe: file /builds/slave/fx-team-l64-000000000000000000/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 760
13:02:43 INFO - 2015-11-23 13:02:43,506 DEBUG : BROWSER_OUTPUT:
13:02:43 INFO - 2015-11-23 13:02:43,506 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:43 INFO - 2015-11-23 13:02:43,506 DEBUG : BROWSER_OUTPUT:
13:02:43 INFO - 2015-11-23 13:02:43,506 DEBUG : BROWSER_OUTPUT:
13:02:43 INFO - 2015-11-23 13:02:43,506 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:43 INFO - 2015-11-23 13:02:43,506 DEBUG : BROWSER_OUTPUT:
13:02:43 INFO - 2015-11-23 13:02:43,506 DEBUG : BROWSER_OUTPUT:
13:02:43 INFO - 2015-11-23 13:02:43,506 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:43 INFO - 2015-11-23 13:02:43,506 DEBUG : BROWSER_OUTPUT:
13:02:43 INFO - 2015-11-23 13:02:43,506 DEBUG : BROWSER_OUTPUT:
13:02:43 INFO - 2015-11-23 13:02:43,506 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:43 INFO - 2015-11-23 13:02:43,507 DEBUG : BROWSER_OUTPUT:
13:02:43 INFO - 2015-11-23 13:02:43,507 DEBUG : BROWSER_OUTPUT:
13:02:43 INFO - 2015-11-23 13:02:43,507 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:43 INFO - 2015-11-23 13:02:43,507 DEBUG : BROWSER_OUTPUT:
13:02:43 INFO - 2015-11-23 13:02:43,507 DEBUG : BROWSER_OUTPUT:
13:02:43 INFO - 2015-11-23 13:02:43,507 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:43 INFO - 2015-11-23 13:02:43,507 DEBUG : BROWSER_OUTPUT:
13:02:43 INFO - 2015-11-23 13:02:43,507 DEBUG : BROWSER_OUTPUT:
13:02:43 INFO - 2015-11-23 13:02:43,507 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:43 INFO - 2015-11-23 13:02:43,507 DEBUG : BROWSER_OUTPUT:
13:02:43 INFO - 2015-11-23 13:02:43,507 DEBUG : BROWSER_OUTPUT:
13:02:43 INFO - 2015-11-23 13:02:43,508 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:43 INFO - 2015-11-23 13:02:43,508 DEBUG : BROWSER_OUTPUT:
13:02:43 INFO - 2015-11-23 13:02:43,508 DEBUG : BROWSER_OUTPUT:
13:02:43 INFO - 2015-11-23 13:02:43,508 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:43 INFO - 2015-11-23 13:02:43,508 DEBUG : BROWSER_OUTPUT:
13:02:43 INFO - 2015-11-23 13:02:43,508 DEBUG : BROWSER_OUTPUT:
13:02:43 INFO - 2015-11-23 13:02:43,508 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:43 INFO - 2015-11-23 13:02:43,508 DEBUG : BROWSER_OUTPUT:
13:02:44 INFO - 2015-11-23 13:02:44,337 INFO : Browser exited with error code: 0
13:02:44 INFO - 2015-11-23 13:02:44,339 INFO : Running cycle 5/10 for sessionrestore test...
13:02:44 INFO - 2015-11-23 13:02:44,339 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpwmMp9m/profile/sessionstore.js
13:02:44 INFO - 2015-11-23 13:02:44,341 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpwmMp9m/profile/sessionCheckpoints.json
13:02:44 INFO - 2015-11-23 13:02:44,342 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpwmMp9m/profile http://localhost:53751/startup_test/sessionrestore/index.html
13:02:49 INFO - 2015-11-23 13:02:49,162 DEBUG : BROWSER_OUTPUT: __start_report1132__end_report
13:02:49 INFO - 2015-11-23 13:02:49,162 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,162 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312569161__endTimestamp
13:02:49 INFO - 2015-11-23 13:02:49,162 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,906 DEBUG : BROWSER_OUTPUT: [Child 6073] 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
13:02:49 INFO - 2015-11-23 13:02:49,907 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,907 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:49 INFO - 2015-11-23 13:02:49,907 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,907 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,907 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:49 INFO - 2015-11-23 13:02:49,907 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,908 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,908 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:49 INFO - 2015-11-23 13:02:49,908 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,908 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,908 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:49 INFO - 2015-11-23 13:02:49,908 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,908 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,908 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:49 INFO - 2015-11-23 13:02:49,908 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,909 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,909 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:49 INFO - 2015-11-23 13:02:49,909 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,909 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,909 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:49 INFO - 2015-11-23 13:02:49,909 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,909 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,909 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:49 INFO - 2015-11-23 13:02:49,909 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,910 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,910 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:49 INFO - 2015-11-23 13:02:49,910 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,910 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,910 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:49 INFO - 2015-11-23 13:02:49,910 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,910 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,910 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:49 INFO - 2015-11-23 13:02:49,910 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,911 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,911 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:49 INFO - 2015-11-23 13:02:49,911 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,911 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,911 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:49 INFO - 2015-11-23 13:02:49,911 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,911 DEBUG : BROWSER_OUTPUT:
13:02:49 INFO - 2015-11-23 13:02:49,911 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:49 INFO - 2015-11-23 13:02:49,911 DEBUG : BROWSER_OUTPUT:
13:02:50 INFO - 2015-11-23 13:02:50,773 INFO : Browser exited with error code: 0
13:02:50 INFO - 2015-11-23 13:02:50,775 INFO : Running cycle 6/10 for sessionrestore test...
13:02:50 INFO - 2015-11-23 13:02:50,775 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpwmMp9m/profile/sessionstore.js
13:02:50 INFO - 2015-11-23 13:02:50,777 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpwmMp9m/profile/sessionCheckpoints.json
13:02:50 INFO - 2015-11-23 13:02:50,778 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpwmMp9m/profile http://localhost:53751/startup_test/sessionrestore/index.html
13:02:55 INFO - 2015-11-23 13:02:55,815 DEBUG : BROWSER_OUTPUT: __start_report1152__end_report
13:02:55 INFO - 2015-11-23 13:02:55,815 DEBUG : BROWSER_OUTPUT:
13:02:55 INFO - 2015-11-23 13:02:55,815 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312575811__endTimestamp
13:02:55 INFO - 2015-11-23 13:02:55,815 DEBUG : BROWSER_OUTPUT:
13:02:56 INFO - 2015-11-23 13:02:56,543 DEBUG : BROWSER_OUTPUT:
13:02:56 INFO - 2015-11-23 13:02:56,543 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:56 INFO - 2015-11-23 13:02:56,543 DEBUG : BROWSER_OUTPUT:
13:02:56 INFO - 2015-11-23 13:02:56,543 DEBUG : BROWSER_OUTPUT:
13:02:56 INFO - 2015-11-23 13:02:56,543 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:56 INFO - 2015-11-23 13:02:56,543 DEBUG : BROWSER_OUTPUT:
13:02:56 INFO - 2015-11-23 13:02:56,543 DEBUG : BROWSER_OUTPUT:
13:02:56 INFO - 2015-11-23 13:02:56,543 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:56 INFO - 2015-11-23 13:02:56,543 DEBUG : BROWSER_OUTPUT:
13:02:56 INFO - 2015-11-23 13:02:56,543 DEBUG : BROWSER_OUTPUT:
13:02:56 INFO - 2015-11-23 13:02:56,544 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:56 INFO - 2015-11-23 13:02:56,544 DEBUG : BROWSER_OUTPUT:
13:02:56 INFO - 2015-11-23 13:02:56,544 DEBUG : BROWSER_OUTPUT:
13:02:56 INFO - 2015-11-23 13:02:56,544 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:56 INFO - 2015-11-23 13:02:56,544 DEBUG : BROWSER_OUTPUT:
13:02:56 INFO - 2015-11-23 13:02:56,544 DEBUG : BROWSER_OUTPUT:
13:02:56 INFO - 2015-11-23 13:02:56,544 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:56 INFO - 2015-11-23 13:02:56,544 DEBUG : BROWSER_OUTPUT:
13:02:56 INFO - 2015-11-23 13:02:56,544 DEBUG : BROWSER_OUTPUT:
13:02:56 INFO - 2015-11-23 13:02:56,544 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:56 INFO - 2015-11-23 13:02:56,545 DEBUG : BROWSER_OUTPUT:
13:02:56 INFO - 2015-11-23 13:02:56,545 DEBUG : BROWSER_OUTPUT:
13:02:56 INFO - 2015-11-23 13:02:56,545 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:56 INFO - 2015-11-23 13:02:56,545 DEBUG : BROWSER_OUTPUT:
13:02:56 INFO - 2015-11-23 13:02:56,545 DEBUG : BROWSER_OUTPUT:
13:02:56 INFO - 2015-11-23 13:02:56,545 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:56 INFO - 2015-11-23 13:02:56,546 DEBUG : BROWSER_OUTPUT:
13:02:56 INFO - 2015-11-23 13:02:56,546 DEBUG : BROWSER_OUTPUT:
13:02:56 INFO - 2015-11-23 13:02:56,546 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:56 INFO - 2015-11-23 13:02:56,546 DEBUG : BROWSER_OUTPUT:
13:02:56 INFO - 2015-11-23 13:02:56,546 DEBUG : BROWSER_OUTPUT:
13:02:56 INFO - 2015-11-23 13:02:56,546 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:56 INFO - 2015-11-23 13:02:56,546 DEBUG : BROWSER_OUTPUT:
13:02:56 INFO - 2015-11-23 13:02:56,547 DEBUG : BROWSER_OUTPUT:
13:02:56 INFO - 2015-11-23 13:02:56,547 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:02:56 INFO - 2015-11-23 13:02:56,547 DEBUG : BROWSER_OUTPUT:
13:02:57 INFO - 2015-11-23 13:02:57,341 INFO : Browser exited with error code: 0
13:02:57 INFO - 2015-11-23 13:02:57,343 INFO : Running cycle 7/10 for sessionrestore test...
13:02:57 INFO - 2015-11-23 13:02:57,343 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpwmMp9m/profile/sessionstore.js
13:02:57 INFO - 2015-11-23 13:02:57,345 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpwmMp9m/profile/sessionCheckpoints.json
13:02:57 INFO - 2015-11-23 13:02:57,346 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpwmMp9m/profile http://localhost:53751/startup_test/sessionrestore/index.html
13:03:02 INFO - 2015-11-23 13:03:02,478 DEBUG : BROWSER_OUTPUT: __start_report1224__end_report
13:03:02 INFO - 2015-11-23 13:03:02,478 DEBUG : BROWSER_OUTPUT:
13:03:02 INFO - 2015-11-23 13:03:02,478 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312582477__endTimestamp
13:03:02 INFO - 2015-11-23 13:03:02,478 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,202 DEBUG : BROWSER_OUTPUT: [Child 6311] WARNING: pipe error: Broken pipe: file /builds/slave/fx-team-l64-000000000000000000/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 760
13:03:03 INFO - 2015-11-23 13:03:03,202 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,202 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:03 INFO - 2015-11-23 13:03:03,203 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,203 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,203 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:03 INFO - 2015-11-23 13:03:03,203 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,203 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,203 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:03 INFO - 2015-11-23 13:03:03,203 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,203 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,203 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:03 INFO - 2015-11-23 13:03:03,203 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,203 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,203 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:03 INFO - 2015-11-23 13:03:03,204 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,204 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,204 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:03 INFO - 2015-11-23 13:03:03,204 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,204 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,204 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:03 INFO - 2015-11-23 13:03:03,204 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,204 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,204 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:03 INFO - 2015-11-23 13:03:03,204 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,204 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,204 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:03 INFO - 2015-11-23 13:03:03,204 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,204 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,205 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:03 INFO - 2015-11-23 13:03:03,205 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,205 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,205 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:03 INFO - 2015-11-23 13:03:03,205 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,205 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,205 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:03 INFO - 2015-11-23 13:03:03,205 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,205 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,205 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:03 INFO - 2015-11-23 13:03:03,205 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,205 DEBUG : BROWSER_OUTPUT:
13:03:03 INFO - 2015-11-23 13:03:03,205 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:03 INFO - 2015-11-23 13:03:03,205 DEBUG : BROWSER_OUTPUT:
13:03:04 INFO - 2015-11-23 13:03:04,090 INFO : Browser exited with error code: 0
13:03:04 INFO - 2015-11-23 13:03:04,091 INFO : Running cycle 8/10 for sessionrestore test...
13:03:04 INFO - 2015-11-23 13:03:04,091 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpwmMp9m/profile/sessionstore.js
13:03:04 INFO - 2015-11-23 13:03:04,093 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpwmMp9m/profile/sessionCheckpoints.json
13:03:04 INFO - 2015-11-23 13:03:04,094 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpwmMp9m/profile http://localhost:53751/startup_test/sessionrestore/index.html
13:03:09 INFO - 2015-11-23 13:03:09,176 DEBUG : BROWSER_OUTPUT: __start_report1165__end_report
13:03:09 INFO - 2015-11-23 13:03:09,176 DEBUG : BROWSER_OUTPUT:
13:03:09 INFO - 2015-11-23 13:03:09,177 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312589174__endTimestamp
13:03:09 INFO - 2015-11-23 13:03:09,177 DEBUG : BROWSER_OUTPUT:
13:03:09 INFO - 2015-11-23 13:03:09,937 DEBUG : BROWSER_OUTPUT:
13:03:09 INFO - 2015-11-23 13:03:09,937 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:09 INFO - 2015-11-23 13:03:09,937 DEBUG : BROWSER_OUTPUT:
13:03:09 INFO - 2015-11-23 13:03:09,937 DEBUG : BROWSER_OUTPUT:
13:03:09 INFO - 2015-11-23 13:03:09,937 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:09 INFO - 2015-11-23 13:03:09,938 DEBUG : BROWSER_OUTPUT:
13:03:09 INFO - 2015-11-23 13:03:09,938 DEBUG : BROWSER_OUTPUT:
13:03:09 INFO - 2015-11-23 13:03:09,938 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:09 INFO - 2015-11-23 13:03:09,938 DEBUG : BROWSER_OUTPUT:
13:03:09 INFO - 2015-11-23 13:03:09,938 DEBUG : BROWSER_OUTPUT:
13:03:09 INFO - 2015-11-23 13:03:09,938 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:09 INFO - 2015-11-23 13:03:09,938 DEBUG : BROWSER_OUTPUT:
13:03:09 INFO - 2015-11-23 13:03:09,938 DEBUG : BROWSER_OUTPUT:
13:03:09 INFO - 2015-11-23 13:03:09,938 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:09 INFO - 2015-11-23 13:03:09,938 DEBUG : BROWSER_OUTPUT:
13:03:09 INFO - 2015-11-23 13:03:09,938 DEBUG : BROWSER_OUTPUT:
13:03:09 INFO - 2015-11-23 13:03:09,938 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:09 INFO - 2015-11-23 13:03:09,938 DEBUG : BROWSER_OUTPUT:
13:03:09 INFO - 2015-11-23 13:03:09,938 DEBUG : BROWSER_OUTPUT:
13:03:09 INFO - 2015-11-23 13:03:09,939 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:09 INFO - 2015-11-23 13:03:09,939 DEBUG : BROWSER_OUTPUT:
13:03:09 INFO - 2015-11-23 13:03:09,939 DEBUG : BROWSER_OUTPUT:
13:03:09 INFO - 2015-11-23 13:03:09,939 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:09 INFO - 2015-11-23 13:03:09,939 DEBUG : BROWSER_OUTPUT:
13:03:09 INFO - 2015-11-23 13:03:09,939 DEBUG : BROWSER_OUTPUT:
13:03:09 INFO - 2015-11-23 13:03:09,939 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:09 INFO - 2015-11-23 13:03:09,939 DEBUG : BROWSER_OUTPUT:
13:03:09 INFO - 2015-11-23 13:03:09,939 DEBUG : BROWSER_OUTPUT:
13:03:09 INFO - 2015-11-23 13:03:09,939 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:09 INFO - 2015-11-23 13:03:09,939 DEBUG : BROWSER_OUTPUT:
13:03:09 INFO - 2015-11-23 13:03:09,939 DEBUG : BROWSER_OUTPUT:
13:03:09 INFO - 2015-11-23 13:03:09,939 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:09 INFO - 2015-11-23 13:03:09,939 DEBUG : BROWSER_OUTPUT:
13:03:10 INFO - 2015-11-23 13:03:10,769 INFO : Browser exited with error code: 0
13:03:10 INFO - 2015-11-23 13:03:10,771 INFO : Running cycle 9/10 for sessionrestore test...
13:03:10 INFO - 2015-11-23 13:03:10,771 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpwmMp9m/profile/sessionstore.js
13:03:10 INFO - 2015-11-23 13:03:10,773 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpwmMp9m/profile/sessionCheckpoints.json
13:03:10 INFO - 2015-11-23 13:03:10,774 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpwmMp9m/profile http://localhost:53751/startup_test/sessionrestore/index.html
13:03:15 INFO - 2015-11-23 13:03:15,709 DEBUG : BROWSER_OUTPUT: __start_report1156__end_report
13:03:15 INFO - 2015-11-23 13:03:15,709 DEBUG : BROWSER_OUTPUT:
13:03:15 INFO - 2015-11-23 13:03:15,709 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312595707__endTimestamp
13:03:15 INFO - 2015-11-23 13:03:15,709 DEBUG : BROWSER_OUTPUT:
13:03:16 INFO - 2015-11-23 13:03:16,434 DEBUG : BROWSER_OUTPUT:
13:03:16 INFO - 2015-11-23 13:03:16,434 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:16 INFO - 2015-11-23 13:03:16,435 DEBUG : BROWSER_OUTPUT:
13:03:16 INFO - 2015-11-23 13:03:16,435 DEBUG : BROWSER_OUTPUT:
13:03:16 INFO - 2015-11-23 13:03:16,435 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:16 INFO - 2015-11-23 13:03:16,435 DEBUG : BROWSER_OUTPUT:
13:03:16 INFO - 2015-11-23 13:03:16,435 DEBUG : BROWSER_OUTPUT:
13:03:16 INFO - 2015-11-23 13:03:16,435 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:16 INFO - 2015-11-23 13:03:16,435 DEBUG : BROWSER_OUTPUT:
13:03:16 INFO - 2015-11-23 13:03:16,435 DEBUG : BROWSER_OUTPUT:
13:03:16 INFO - 2015-11-23 13:03:16,435 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:16 INFO - 2015-11-23 13:03:16,435 DEBUG : BROWSER_OUTPUT:
13:03:16 INFO - 2015-11-23 13:03:16,435 DEBUG : BROWSER_OUTPUT:
13:03:16 INFO - 2015-11-23 13:03:16,435 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:16 INFO - 2015-11-23 13:03:16,435 DEBUG : BROWSER_OUTPUT:
13:03:16 INFO - 2015-11-23 13:03:16,435 DEBUG : BROWSER_OUTPUT:
13:03:16 INFO - 2015-11-23 13:03:16,435 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:16 INFO - 2015-11-23 13:03:16,435 DEBUG : BROWSER_OUTPUT:
13:03:16 INFO - 2015-11-23 13:03:16,436 DEBUG : BROWSER_OUTPUT:
13:03:16 INFO - 2015-11-23 13:03:16,436 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:16 INFO - 2015-11-23 13:03:16,436 DEBUG : BROWSER_OUTPUT:
13:03:16 INFO - 2015-11-23 13:03:16,436 DEBUG : BROWSER_OUTPUT:
13:03:16 INFO - 2015-11-23 13:03:16,436 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:16 INFO - 2015-11-23 13:03:16,436 DEBUG : BROWSER_OUTPUT:
13:03:16 INFO - 2015-11-23 13:03:16,436 DEBUG : BROWSER_OUTPUT:
13:03:16 INFO - 2015-11-23 13:03:16,436 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:16 INFO - 2015-11-23 13:03:16,436 DEBUG : BROWSER_OUTPUT:
13:03:17 INFO - 2015-11-23 13:03:17,313 INFO : Browser exited with error code: 0
13:03:17 INFO - 2015-11-23 13:03:17,315 INFO : Running cycle 10/10 for sessionrestore test...
13:03:17 INFO - 2015-11-23 13:03:17,315 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpwmMp9m/profile/sessionstore.js
13:03:17 INFO - 2015-11-23 13:03:17,317 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpwmMp9m/profile/sessionCheckpoints.json
13:03:17 INFO - 2015-11-23 13:03:17,318 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpwmMp9m/profile http://localhost:53751/startup_test/sessionrestore/index.html
13:03:22 INFO - 2015-11-23 13:03:22,321 DEBUG : BROWSER_OUTPUT: __start_report1173__end_report
13:03:22 INFO - 2015-11-23 13:03:22,321 DEBUG : BROWSER_OUTPUT:
13:03:22 INFO - 2015-11-23 13:03:22,321 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312602316__endTimestamp
13:03:22 INFO - 2015-11-23 13:03:22,321 DEBUG : BROWSER_OUTPUT:
13:03:23 INFO - 2015-11-23 13:03:23,017 DEBUG : BROWSER_OUTPUT: [Child 6667] 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
13:03:23 INFO - 2015-11-23 13:03:23,017 DEBUG : BROWSER_OUTPUT:
13:03:23 INFO - 2015-11-23 13:03:23,017 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:23 INFO - 2015-11-23 13:03:23,017 DEBUG : BROWSER_OUTPUT:
13:03:23 INFO - 2015-11-23 13:03:23,017 DEBUG : BROWSER_OUTPUT:
13:03:23 INFO - 2015-11-23 13:03:23,017 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:23 INFO - 2015-11-23 13:03:23,017 DEBUG : BROWSER_OUTPUT:
13:03:23 INFO - 2015-11-23 13:03:23,018 DEBUG : BROWSER_OUTPUT:
13:03:23 INFO - 2015-11-23 13:03:23,018 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:23 INFO - 2015-11-23 13:03:23,018 DEBUG : BROWSER_OUTPUT:
13:03:23 INFO - 2015-11-23 13:03:23,018 DEBUG : BROWSER_OUTPUT:
13:03:23 INFO - 2015-11-23 13:03:23,018 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:23 INFO - 2015-11-23 13:03:23,018 DEBUG : BROWSER_OUTPUT:
13:03:23 INFO - 2015-11-23 13:03:23,018 DEBUG : BROWSER_OUTPUT:
13:03:23 INFO - 2015-11-23 13:03:23,018 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:23 INFO - 2015-11-23 13:03:23,018 DEBUG : BROWSER_OUTPUT:
13:03:23 INFO - 2015-11-23 13:03:23,018 DEBUG : BROWSER_OUTPUT:
13:03:23 INFO - 2015-11-23 13:03:23,019 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:23 INFO - 2015-11-23 13:03:23,019 DEBUG : BROWSER_OUTPUT:
13:03:23 INFO - 2015-11-23 13:03:23,019 DEBUG : BROWSER_OUTPUT:
13:03:23 INFO - 2015-11-23 13:03:23,019 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:23 INFO - 2015-11-23 13:03:23,019 DEBUG : BROWSER_OUTPUT:
13:03:23 INFO - 2015-11-23 13:03:23,019 DEBUG : BROWSER_OUTPUT:
13:03:23 INFO - 2015-11-23 13:03:23,019 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:23 INFO - 2015-11-23 13:03:23,019 DEBUG : BROWSER_OUTPUT:
13:03:23 INFO - 2015-11-23 13:03:23,019 DEBUG : BROWSER_OUTPUT:
13:03:23 INFO - 2015-11-23 13:03:23,019 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:23 INFO - 2015-11-23 13:03:23,020 DEBUG : BROWSER_OUTPUT:
13:03:23 INFO - 2015-11-23 13:03:23,020 DEBUG : BROWSER_OUTPUT:
13:03:23 INFO - 2015-11-23 13:03:23,020 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:23 INFO - 2015-11-23 13:03:23,020 DEBUG : BROWSER_OUTPUT:
13:03:23 INFO - 2015-11-23 13:03:23,020 DEBUG : BROWSER_OUTPUT:
13:03:23 INFO - 2015-11-23 13:03:23,020 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:23 INFO - 2015-11-23 13:03:23,020 DEBUG : BROWSER_OUTPUT:
13:03:23 INFO - 2015-11-23 13:03:23,020 DEBUG : BROWSER_OUTPUT:
13:03:23 INFO - 2015-11-23 13:03:23,020 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
13:03:23 INFO - 2015-11-23 13:03:23,020 DEBUG : BROWSER_OUTPUT:
13:03:23 INFO - 2015-11-23 13:03:23,865 INFO : Browser exited with error code: 0
13:03:23 INFO - 2015-11-23 13:03:23,879 INFO : Completed test sessionrestore (00:01:15)
13:03:23 INFO - 2015-11-23 13:03:23,879 INFO : Starting test sessionrestore_no_auto_restore
13:03:23 INFO - 2015-11-23 13:03:23,879 DEBUG : operating with platform_type : linux_
13:03:23 INFO - 2015-11-23 13:03:23,880 INFO : Initialising browser for sessionrestore_no_auto_restore test...
13:03:23 INFO - 2015-11-23 13:03:23,888 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpnltrUj/profile http://localhost:53751/getInfo.html
13:03:27 INFO - 2015-11-23 13:03:27,833 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
13:03:27 INFO - 2015-11-23 13:03:27,833 DEBUG : BROWSER_OUTPUT: colorDepth:24
13:03:27 INFO - 2015-11-23 13:03:27,833 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1151/811
13:03:27 INFO - 2015-11-23 13:03:27,833 DEBUG : BROWSER_OUTPUT: __metrics
13:03:28 INFO - 2015-11-23 13:03:28,981 INFO : Browser initialized.
13:03:28 INFO - 2015-11-23 13:03:28,982 INFO : Running cycle 1/10 for sessionrestore_no_auto_restore test...
13:03:28 INFO - 2015-11-23 13:03:28,982 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpnltrUj/profile/sessionstore.js
13:03:28 INFO - 2015-11-23 13:03:28,984 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpnltrUj/profile/sessionCheckpoints.json
13:03:28 INFO - 2015-11-23 13:03:28,985 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpnltrUj/profile http://localhost:53751/startup_test/sessionrestore/index.html
13:03:31 INFO - 2015-11-23 13:03:31,168 DEBUG : BROWSER_OUTPUT: __start_report1166__end_report
13:03:31 INFO - 2015-11-23 13:03:31,169 DEBUG : BROWSER_OUTPUT:
13:03:31 INFO - 2015-11-23 13:03:31,169 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312611165__endTimestamp
13:03:31 INFO - 2015-11-23 13:03:31,169 DEBUG : BROWSER_OUTPUT:
13:03:32 INFO - 2015-11-23 13:03:32,181 INFO : Browser exited with error code: 0
13:03:32 INFO - 2015-11-23 13:03:32,183 INFO : Running cycle 2/10 for sessionrestore_no_auto_restore test...
13:03:32 INFO - 2015-11-23 13:03:32,183 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpnltrUj/profile/sessionstore.js
13:03:32 INFO - 2015-11-23 13:03:32,185 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpnltrUj/profile/sessionCheckpoints.json
13:03:32 INFO - 2015-11-23 13:03:32,186 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpnltrUj/profile http://localhost:53751/startup_test/sessionrestore/index.html
13:03:33 INFO - 2015-11-23 13:03:33,740 DEBUG : BROWSER_OUTPUT: __start_report741__end_report
13:03:33 INFO - 2015-11-23 13:03:33,740 DEBUG : BROWSER_OUTPUT:
13:03:33 INFO - 2015-11-23 13:03:33,740 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312613733__endTimestamp
13:03:33 INFO - 2015-11-23 13:03:33,740 DEBUG : BROWSER_OUTPUT:
13:03:34 INFO - 2015-11-23 13:03:34,609 INFO : Browser exited with error code: 0
13:03:34 INFO - 2015-11-23 13:03:34,611 INFO : Running cycle 3/10 for sessionrestore_no_auto_restore test...
13:03:34 INFO - 2015-11-23 13:03:34,611 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpnltrUj/profile/sessionstore.js
13:03:34 INFO - 2015-11-23 13:03:34,613 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpnltrUj/profile/sessionCheckpoints.json
13:03:34 INFO - 2015-11-23 13:03:34,614 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpnltrUj/profile http://localhost:53751/startup_test/sessionrestore/index.html
13:03:36 INFO - 2015-11-23 13:03:36,177 DEBUG : BROWSER_OUTPUT: __start_report747__end_report
13:03:36 INFO - 2015-11-23 13:03:36,177 DEBUG : BROWSER_OUTPUT:
13:03:36 INFO - 2015-11-23 13:03:36,177 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312616175__endTimestamp
13:03:36 INFO - 2015-11-23 13:03:36,177 DEBUG : BROWSER_OUTPUT:
13:03:37 INFO - 2015-11-23 13:03:37,149 INFO : Browser exited with error code: 0
13:03:37 INFO - 2015-11-23 13:03:37,151 INFO : Running cycle 4/10 for sessionrestore_no_auto_restore test...
13:03:37 INFO - 2015-11-23 13:03:37,151 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpnltrUj/profile/sessionstore.js
13:03:37 INFO - 2015-11-23 13:03:37,153 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpnltrUj/profile/sessionCheckpoints.json
13:03:37 INFO - 2015-11-23 13:03:37,154 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpnltrUj/profile http://localhost:53751/startup_test/sessionrestore/index.html
13:03:38 INFO - 2015-11-23 13:03:38,753 DEBUG : BROWSER_OUTPUT: __start_report750__end_report
13:03:38 INFO - 2015-11-23 13:03:38,754 DEBUG : BROWSER_OUTPUT:
13:03:38 INFO - 2015-11-23 13:03:38,754 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312618753__endTimestamp
13:03:38 INFO - 2015-11-23 13:03:38,754 DEBUG : BROWSER_OUTPUT:
13:03:39 INFO - 2015-11-23 13:03:39,757 INFO : Browser exited with error code: 0
13:03:39 INFO - 2015-11-23 13:03:39,759 INFO : Running cycle 5/10 for sessionrestore_no_auto_restore test...
13:03:39 INFO - 2015-11-23 13:03:39,759 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpnltrUj/profile/sessionstore.js
13:03:39 INFO - 2015-11-23 13:03:39,761 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpnltrUj/profile/sessionCheckpoints.json
13:03:39 INFO - 2015-11-23 13:03:39,761 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpnltrUj/profile http://localhost:53751/startup_test/sessionrestore/index.html
13:03:41 INFO - 2015-11-23 13:03:41,341 DEBUG : BROWSER_OUTPUT: __start_report743__end_report
13:03:41 INFO - 2015-11-23 13:03:41,342 DEBUG : BROWSER_OUTPUT:
13:03:41 INFO - 2015-11-23 13:03:41,342 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312621338__endTimestamp
13:03:41 INFO - 2015-11-23 13:03:41,342 DEBUG : BROWSER_OUTPUT:
13:03:42 INFO - 2015-11-23 13:03:42,381 INFO : Browser exited with error code: 0
13:03:42 INFO - 2015-11-23 13:03:42,383 INFO : Running cycle 6/10 for sessionrestore_no_auto_restore test...
13:03:42 INFO - 2015-11-23 13:03:42,383 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpnltrUj/profile/sessionstore.js
13:03:42 INFO - 2015-11-23 13:03:42,385 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpnltrUj/profile/sessionCheckpoints.json
13:03:42 INFO - 2015-11-23 13:03:42,386 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpnltrUj/profile http://localhost:53751/startup_test/sessionrestore/index.html
13:03:43 INFO - 2015-11-23 13:03:43,943 DEBUG : BROWSER_OUTPUT: __start_report742__end_report
13:03:43 INFO - 2015-11-23 13:03:43,943 DEBUG : BROWSER_OUTPUT:
13:03:43 INFO - 2015-11-23 13:03:43,943 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312623943__endTimestamp
13:03:43 INFO - 2015-11-23 13:03:43,944 DEBUG : BROWSER_OUTPUT:
13:03:44 INFO - 2015-11-23 13:03:44,957 INFO : Browser exited with error code: 0
13:03:44 INFO - 2015-11-23 13:03:44,959 INFO : Running cycle 7/10 for sessionrestore_no_auto_restore test...
13:03:44 INFO - 2015-11-23 13:03:44,959 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpnltrUj/profile/sessionstore.js
13:03:44 INFO - 2015-11-23 13:03:44,961 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpnltrUj/profile/sessionCheckpoints.json
13:03:44 INFO - 2015-11-23 13:03:44,962 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpnltrUj/profile http://localhost:53751/startup_test/sessionrestore/index.html
13:03:46 INFO - 2015-11-23 13:03:46,547 DEBUG : BROWSER_OUTPUT: __start_report744__end_report
13:03:46 INFO - 2015-11-23 13:03:46,547 DEBUG : BROWSER_OUTPUT:
13:03:46 INFO - 2015-11-23 13:03:46,547 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312626547__endTimestamp
13:03:46 INFO - 2015-11-23 13:03:46,548 DEBUG : BROWSER_OUTPUT:
13:03:47 INFO - 2015-11-23 13:03:47,569 INFO : Browser exited with error code: 0
13:03:47 INFO - 2015-11-23 13:03:47,571 INFO : Running cycle 8/10 for sessionrestore_no_auto_restore test...
13:03:47 INFO - 2015-11-23 13:03:47,571 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpnltrUj/profile/sessionstore.js
13:03:47 INFO - 2015-11-23 13:03:47,573 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpnltrUj/profile/sessionCheckpoints.json
13:03:47 INFO - 2015-11-23 13:03:47,574 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpnltrUj/profile http://localhost:53751/startup_test/sessionrestore/index.html
13:03:49 INFO - 2015-11-23 13:03:49,155 DEBUG : BROWSER_OUTPUT: __start_report745__end_report
13:03:49 INFO - 2015-11-23 13:03:49,156 DEBUG : BROWSER_OUTPUT:
13:03:49 INFO - 2015-11-23 13:03:49,156 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312629155__endTimestamp
13:03:49 INFO - 2015-11-23 13:03:49,156 DEBUG : BROWSER_OUTPUT:
13:03:50 INFO - 2015-11-23 13:03:50,209 INFO : Browser exited with error code: 0
13:03:50 INFO - 2015-11-23 13:03:50,211 INFO : Running cycle 9/10 for sessionrestore_no_auto_restore test...
13:03:50 INFO - 2015-11-23 13:03:50,211 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpnltrUj/profile/sessionstore.js
13:03:50 INFO - 2015-11-23 13:03:50,213 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpnltrUj/profile/sessionCheckpoints.json
13:03:50 INFO - 2015-11-23 13:03:50,214 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpnltrUj/profile http://localhost:53751/startup_test/sessionrestore/index.html
13:03:51 INFO - 2015-11-23 13:03:51,849 DEBUG : BROWSER_OUTPUT: __start_report782__end_report
13:03:51 INFO - 2015-11-23 13:03:51,849 DEBUG : BROWSER_OUTPUT:
13:03:51 INFO - 2015-11-23 13:03:51,849 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312631844__endTimestamp
13:03:51 INFO - 2015-11-23 13:03:51,849 DEBUG : BROWSER_OUTPUT:
13:03:52 INFO - 2015-11-23 13:03:52,941 INFO : Browser exited with error code: 0
13:03:52 INFO - 2015-11-23 13:03:52,943 INFO : Running cycle 10/10 for sessionrestore_no_auto_restore test...
13:03:52 INFO - 2015-11-23 13:03:52,943 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpnltrUj/profile/sessionstore.js
13:03:52 INFO - 2015-11-23 13:03:52,945 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpnltrUj/profile/sessionCheckpoints.json
13:03:52 INFO - 2015-11-23 13:03:52,946 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpnltrUj/profile http://localhost:53751/startup_test/sessionrestore/index.html
13:03:54 INFO - 2015-11-23 13:03:54,549 DEBUG : BROWSER_OUTPUT: __start_report744__end_report
13:03:54 INFO - 2015-11-23 13:03:54,549 DEBUG : BROWSER_OUTPUT:
13:03:54 INFO - 2015-11-23 13:03:54,549 DEBUG : BROWSER_OUTPUT: __startTimestamp1448312634547__endTimestamp
13:03:54 INFO - 2015-11-23 13:03:54,549 DEBUG : BROWSER_OUTPUT:
13:03:55 INFO - 2015-11-23 13:03:55,617 INFO : Browser exited with error code: 0
13:03:55 INFO - 2015-11-23 13:03:55,630 INFO : Completed test sessionrestore_no_auto_restore (00:00:31)
13:03:55 INFO - 2015-11-23 13:03:55,965 INFO : Completed test suite (00:05:08)
13:03:55 INFO - 2015-11-23 13:03:55,965 DEBUG : Working with test: a11yr
13:03:55 INFO - 2015-11-23 13:03:55,965 DEBUG : Generating results file: a11yr
13:03:55 INFO - 2015-11-23 13:03:55,965 DEBUG : Working with test: ts_paint
13:03:55 INFO - 2015-11-23 13:03:55,966 DEBUG : Generating results file: ts_paint
13:03:55 INFO - 2015-11-23 13:03:55,966 DEBUG : Working with test: tpaint
13:03:55 INFO - 2015-11-23 13:03:55,966 DEBUG : Generating results file: tpaint
13:03:55 INFO - 2015-11-23 13:03:55,967 DEBUG : Working with test: sessionrestore
13:03:55 INFO - 2015-11-23 13:03:55,967 DEBUG : Generating results file: sessionrestore
13:03:55 INFO - 2015-11-23 13:03:55,967 DEBUG : Working with test: sessionrestore_no_auto_restore
13:03:55 INFO - 2015-11-23 13:03:55,967 DEBUG : Generating results file: sessionrestore_no_auto_restore
13:03:55 INFO - 2015-11-23 13:03:55,968 INFO : Posting result 0 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
13:03:56 INFO - 2015-11-23 13:03:56,017 DEBUG : process_Request line: a11yr_paint graph.html#tests=[[223,132,43]]
13:03:56 INFO - 2015-11-23 13:03:56,017 DEBUG : process_Request line: a11yr_paint 709.15 graph.html#tests=[[223,132,43]]
13:03:56 INFO - 2015-11-23 13:03:56,017 INFO : Posting result 1 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
13:03:56 INFO - 2015-11-23 13:03:56,084 DEBUG : process_Request line: ts_paint graph.html#tests=[[83,132,43]]
13:03:56 INFO - 2015-11-23 13:03:56,084 DEBUG : process_Request line: ts_paint 528.16 graph.html#tests=[[83,132,43]]
13:03:56 INFO - 2015-11-23 13:03:56,084 INFO : Posting result 2 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
13:03:56 INFO - 2015-11-23 13:03:56,123 DEBUG : process_Request line: tpaint graph.html#tests=[[82,132,43]]
13:03:56 INFO - 2015-11-23 13:03:56,123 DEBUG : process_Request line: tpaint 316.99 graph.html#tests=[[82,132,43]]
13:03:56 INFO - 2015-11-23 13:03:56,123 INFO : Posting result 3 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
13:03:56 INFO - 2015-11-23 13:03:56,179 DEBUG : process_Request line: sessionrestore graph.html#tests=[[313,132,43]]
13:03:56 INFO - 2015-11-23 13:03:56,179 DEBUG : process_Request line: sessionrestore 1193.39 graph.html#tests=[[313,132,43]]
13:03:56 INFO - 2015-11-23 13:03:56,179 INFO : Posting result 4 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
13:03:56 INFO - 2015-11-23 13:03:56,246 DEBUG : process_Request line: sessionrestore_no_auto_restore graph.html#tests=[[315,132,43]]
13:03:56 INFO - 2015-11-23 13:03:56,246 DEBUG : process_Request line: sessionrestore_no_auto_restore 782.50 graph.html#tests=[[315,132,43]]
13:03:56 INFO - 2015-11-23 13:03:56,247 INFO : PERFHERDER_DATA: {"framework": {"name": "talos"}, "suites": [{"lowerIsBetter": true, "subtests": [{"lowerIsBetter": true, "replicates": [1243.0, 1294.0, 1291.0, 1294.0, 1312.0, 1308.0, 1317.0, 1306.0, 1299.0, 1307.0, 1309.0, 1302.0, 1302.0, 1312.0, 1310.0, 1301.0, 1298.0, 1305.0, 1303.0, 1306.0, 1524.0, 1301.0, 1305.0, 1319.0, 1550.0], "unit": "ms", "name": "dhtml.html", "value": 1305.5}, {"lowerIsBetter": true, "replicates": [379.0, 382.0, 395.0, 386.0, 388.0, 394.0, 383.0, 384.0, 374.0, 385.0, 380.0, 393.0, 388.0, 385.0, 376.0, 385.0, 391.0, 379.0, 393.0, 376.0, 381.0, 386.0, 387.0, 387.0, 384.0], "unit": "ms", "name": "tablemutation.html", "value": 385.0}], "name": "a11yr", "value": 709.1471678462153}, {"subtests": [{"replicates": [499.0, 538.0, 572.0, 587.0, 498.0, 562.0, 537.0, 494.0, 535.0, 540.0, 498.0, 496.0, 504.0, 519.0, 547.0, 538.0, 537.0, 543.0, 528.0, 504.0], "name": "ts_paint", "value": 537.0}], "name": "ts_paint", "value": 537.0}, {"subtests": [{"replicates": [228.32500000000073, 243.3050000000003, 256.90499999999975, 261.0749999999998, 268.0100000000002, 283.0750000000007, 283.21000000000004, 286.9250000000029, 290.9549999999999, 294.21500000000015, 301.1949999999997, 316.375, 316.9900000000016, 317.3250000000007, 319.7649999999994, 327.375, 353.59999999999945, 353.880000000001, 379.15500000000065, 411.71000000000095], "name": "tpaint", "value": 316.9900000000016}], "name": "tpaint", "value": 316.9900000000016}, {"subtests": [{"replicates": [1476.0, 1171.0, 1150.0, 1169.0, 1132.0, 1152.0, 1224.0, 1165.0, 1156.0, 1173.0], "name": "sessionrestore", "value": 1165.0}], "name": "sessionrestore", "value": 1165.0}, {"subtests": [{"replicates": [1166.0, 741.0, 747.0, 750.0, 743.0, 742.0, 744.0, 745.0, 782.0, 744.0], "name": "sessionrestore_no_auto_restore", "value": 744.0}], "name": "sessionrestore_no_auto_restore", "value": 744.0}]}
13:03:56 INFO - RETURN: a11yr_paint: 709.15
13:03:56 INFO - RETURN: ts_paint: 528.16
13:03:56 INFO - RETURN: tpaint: 316.99
13:03:56 INFO - RETURN: sessionrestore: 1193.39
13:03:56 INFO - RETURN: sessionrestore_no_auto_restore: 782.50
13:03:56 INFO - TinderboxPrint: TalosResult: {"graphserver": {"sessionrestore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[313,132,43]]", "result": "1193.39"}, "a11yr_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[223,132,43]]", "result": "709.15"}, "tpaint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[82,132,43]]", "result": "316.99"}, "ts_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[83,132,43]]", "result": "528.16"}, "sessionrestore_no_auto_restore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[315,132,43]]", "result": "782.50"}}}
13:03:56 INFO - Return code: 0
13:03:56 ERROR - # TBPL SUCCESS #
13:03:56 INFO - Running post-action listener: _resource_record_post_action
13:03:56 INFO - Running post-run listener: _resource_record_post_run
13:03:57 INFO - Total resource usage - Wall time: 323s; CPU: 15.0%; Read bytes: 20480; Write bytes: 582303744; Read time: 28; Write time: 409780
13:03:57 INFO - install - Wall time: 14s; CPU: 14.0%; Read bytes: 0; Write bytes: 233480192; Read time: 0; Write time: 271216
13:03:57 INFO - run-tests - Wall time: 309s; CPU: 16.0%; Read bytes: 20480; Write bytes: 348823552; Read time: 28; Write time: 138564
13:03:57 INFO - Running post-run listener: _upload_blobber_files
13:03:57 INFO - Blob upload gear active.
13:03:57 INFO - There are no files to upload in the directory. Skipping the blob upload mechanism ...
13:03:57 INFO - Copying logs to upload dir...
13:03:57 INFO - mkdir: /builds/slave/test/build/upload/logs
program finished with exit code 0
elapsedTime=351.615704
========= master_lag: 0.03 =========
========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 5 mins, 51 secs) (at 2015-11-23 13:03:57.241197) =========
========= Started set props: build_url (results: 0, elapsed: 0 secs) (at 2015-11-23 13:03:57.244850) =========
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=919420d7ee4ef147bef0346300000385-1448312283.868710-972446830
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
build_url:https://queue.taskcluster.net/v1/task/WsFfSGx8Qu2guP2wehmoyw/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2
program finished with exit code 0
elapsedTime=0.009911
build_url: 'https://queue.taskcluster.net/v1/task/WsFfSGx8Qu2guP2wehmoyw/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-23 13:03:57.296261) =========
========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-11-23 13:03:57.296595) =========
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=919420d7ee4ef147bef0346300000385-1448312283.868710-972446830
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
program finished with exit code 0
elapsedTime=0.004494
========= master_lag: 0.05 =========
========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-11-23 13:03:57.346216) =========
========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2015-11-23 13:03:57.346524) =========
========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2015-11-23 13:03:57.346802) =========
========= Total master_lag: 0.24 =========