builder: fx-team_ubuntu64_hw_test-other-e10s
slave: talos-linux64-ix-045
starttime: 1447870777.07
results: success (0)
buildid: 20151118091623
builduid: 28474222b74b4731a603f3978a06f218
revision: 1d6ba006a526d17294369eed770a9a0ce2794bde
========= Started set props: master (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.074866) =========
master: http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/
========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.075394) =========
========= Started set props: basedir (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.075678) =========
bash -c pwd
in dir /builds/slave/test/. (timeout 1200 secs)
watching logfiles {}
argv: ['bash', '-c', 'pwd']
environment:
DISPLAY=:0
HOME=/home/cltbld
LANG=en_US.UTF-8
LANGUAGE=en_US:en
LOGNAME=cltbld
MAIL=/var/mail/cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript
NO_EM_RESTART=1
PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
PWD=/builds/slave/test
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
/builds/slave/test
program finished with exit code 0
elapsedTime=0.006584
basedir: '/builds/slave/test'
========= master_lag: 0.01 =========
========= Finished set props: basedir (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.095322) =========
========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.095610) =========
========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.103452) =========
========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.103766) =========
rm -rf properties
in dir /builds/slave/test/. (timeout 1200 secs)
watching logfiles {}
argv: ['rm', '-rf', 'properties']
environment:
DISPLAY=:0
HOME=/home/cltbld
LANG=en_US.UTF-8
LANGUAGE=en_US:en
LOGNAME=cltbld
MAIL=/var/mail/cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript
NO_EM_RESTART=1
PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
PWD=/builds/slave/test
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
program finished with exit code 0
elapsedTime=0.004512
========= master_lag: 0.04 =========
========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.152923) =========
========= Started set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.153235) =========
script_repo_url: https://hg.mozilla.org/build/mozharness
========= Finished set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.153589) =========
========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.153856) =========
bash -c 'wget -Oarchiver_client.py --no-check-certificate --tries=10 --waitretry=3 https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py'
in dir /builds/slave/test/. (timeout 1200 secs)
watching logfiles {}
argv: ['bash', '-c', 'wget -Oarchiver_client.py --no-check-certificate --tries=10 --waitretry=3 https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py']
environment:
DISPLAY=:0
HOME=/home/cltbld
LANG=en_US.UTF-8
LANGUAGE=en_US:en
LOGNAME=cltbld
MAIL=/var/mail/cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript
NO_EM_RESTART=1
PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
PWD=/builds/slave/test
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
--2015-11-18 10:19:37-- https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py
Resolving hg.mozilla.org (hg.mozilla.org)... 63.245.215.102, 63.245.215.25
Connecting to hg.mozilla.org (hg.mozilla.org)|63.245.215.102|:443... connected.
HTTP request sent, awaiting response... 200 Script output follows
Length: 12141 (12K) [text/x-python]
Saving to: `archiver_client.py'
0K .......... . 100% 5.81M=0.002s
2015-11-18 10:19:37 (5.81 MB/s) - `archiver_client.py' saved [12141/12141]
program finished with exit code 0
elapsedTime=0.192586
========= master_lag: 0.01 =========
========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.358612) =========
========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.358920) =========
rm -rf scripts
in dir /builds/slave/test/. (timeout 1200 secs)
watching logfiles {}
argv: ['rm', '-rf', 'scripts']
environment:
DISPLAY=:0
HOME=/home/cltbld
LANG=en_US.UTF-8
LANGUAGE=en_US:en
LOGNAME=cltbld
MAIL=/var/mail/cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript
NO_EM_RESTART=1
PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
PWD=/builds/slave/test
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
program finished with exit code 0
elapsedTime=0.014413
========= master_lag: 0.04 =========
========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.408842) =========
========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.409200) =========
bash -c 'python archiver_client.py mozharness --repo integration/fx-team --rev 1d6ba006a526d17294369eed770a9a0ce2794bde --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 1d6ba006a526d17294369eed770a9a0ce2794bde --destination scripts --debug']
environment:
DISPLAY=:0
HOME=/home/cltbld
LANG=en_US.UTF-8
LANGUAGE=en_US:en
LOGNAME=cltbld
MAIL=/var/mail/cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript
NO_EM_RESTART=1
PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
PWD=/builds/slave/test
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
2015-11-18 10:19:38,091 truncating revision to first 12 chars
2015-11-18 10:19:38,091 Setting DEBUG logging.
2015-11-18 10:19:38,091 attempt 1/10
2015-11-18 10:19:38,091 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/integration/fx-team/1d6ba006a526?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness
2015-11-18 10:19:38,330 unpacking tar archive at: fx-team-1d6ba006a526/testing/mozharness/
program finished with exit code 0
elapsedTime=0.527983
========= master_lag: 0.01 =========
========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.950145) =========
========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.950498) =========
========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.958440) =========
========= Started tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.958749) =========
TinderboxPrint: script_revlink: https://hg.mozilla.org/build/mozharness/rev/production
========= Finished tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.959198) =========
========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 5 mins, 59 secs) (at 2015-11-18 10:19:37.959562) =========
/tools/buildbot/bin/python scripts/scripts/talos_script.py --suite other-e10s --add-option --webServer,localhost --branch-name Fx-Team-Non-PGO --system-bits 64 --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Fx-Team-Non-PGO
in dir /builds/slave/test/. (timeout 3600 secs) (maxTime 7200 secs)
watching logfiles {}
argv: ['/tools/buildbot/bin/python', 'scripts/scripts/talos_script.py', '--suite', 'other-e10s', '--add-option', '--webServer,localhost', '--branch-name', 'Fx-Team-Non-PGO', '--system-bits', '64', '--cfg', 'talos/linux_config.py', '--download-symbols', 'ondemand', '--use-talos-json', '--blob-upload-branch', 'Fx-Team-Non-PGO']
environment:
DISPLAY=:0
HOME=/home/cltbld
LANG=en_US.UTF-8
LANGUAGE=en_US:en
LOGNAME=cltbld
MAIL=/var/mail/cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript
NO_EM_RESTART=1
PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
PROPERTIES_FILE=/builds/slave/test/buildprops.json
PWD=/builds/slave/test
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
10:19:38 INFO - MultiFileLogger online at 20151118 10:19:38 in /builds/slave/test
10:19:38 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
10:19:38 INFO - Dumping config to /builds/slave/test/logs/localconfig.json.
10:19:38 INFO - {'append_to_log': False,
10:19:38 INFO - 'base_work_dir': '/builds/slave/test',
10:19:38 INFO - 'blob_upload_branch': 'Fx-Team-Non-PGO',
10:19:38 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt',
10:19:38 INFO - 'branch': 'Fx-Team-Non-PGO',
10:19:38 INFO - 'buildbot_json_path': 'buildprops.json',
10:19:38 INFO - 'config_files': ('talos/linux_config.py',),
10:19:38 INFO - 'default_actions': ('clobber',
10:19:38 INFO - 'read-buildbot-config',
10:19:38 INFO - 'download-and-extract',
10:19:38 INFO - 'populate-webroot',
10:19:38 INFO - 'create-virtualenv',
10:19:38 INFO - 'install',
10:19:38 INFO - 'run-tests'),
10:19:38 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',),
10:19:38 INFO - 'download_minidump_stackwalk': True,
10:19:38 INFO - 'download_symbols': 'ondemand',
10:19:38 INFO - 'exes': {'python': '/tools/buildbot/bin/python',
10:19:38 INFO - 'tooltool.py': '/tools/tooltool.py',
10:19:38 INFO - 'virtualenv': ('/tools/buildbot/bin/python',
10:19:38 INFO - '/tools/misc-python/virtualenv.py')},
10:19:38 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub',
10:19:38 INFO - 'http://pypi.pub.build.mozilla.org/pub'),
10:19:38 INFO - 'installer_path': 'installer.exe',
10:19:38 INFO - 'log_level': 'info',
10:19:38 INFO - 'log_name': 'talos',
10:19:38 INFO - 'log_to_console': True,
10:19:38 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk',
10:19:38 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest',
10:19:38 INFO - 'opt_config_files': (),
10:19:38 INFO - 'pip_index': False,
10:19:38 INFO - 'sps_profile': False,
10:19:38 INFO - 'sps_profile_interval': 0,
10:19:38 INFO - 'suite': 'other-e10s',
10:19:38 INFO - 'system_bits': '64',
10:19:38 INFO - 'talos_extra_options': ('--webServer', 'localhost'),
10:19:38 INFO - 'title': 'talos-linux64-ix-045',
10:19:38 INFO - 'tooltool_cache': '/builds/tooltool_cache',
10:19:38 INFO - 'use_talos_json': True,
10:19:38 INFO - 'virtualenv_path': '/builds/slave/test/build/venv',
10:19:38 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None},
10:19:38 INFO - 'work_dir': 'build'}
10:19:38 INFO - #####
10:19:38 INFO - ##### Running clobber step.
10:19:38 INFO - #####
10:19:38 INFO - Running pre-action listener: _resource_record_pre_action
10:19:38 INFO - Running main action method: clobber
10:19:38 INFO - rmtree: /builds/slave/test/build
10:19:38 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1
10:19:39 INFO - Running post-action listener: _resource_record_post_action
10:19:39 INFO - #####
10:19:39 INFO - ##### Running read-buildbot-config step.
10:19:39 INFO - #####
10:19:39 INFO - Running pre-action listener: _resource_record_pre_action
10:19:39 INFO - Running main action method: read_buildbot_config
10:19:39 INFO - Using buildbot properties:
10:19:39 INFO - {
10:19:39 INFO - "properties": {
10:19:39 INFO - "buildnumber": 485,
10:19:39 INFO - "product": "firefox",
10:19:39 INFO - "script_repo_revision": "production",
10:19:39 INFO - "builddir": "fx-team_ubuntu64_hw_test-other-e10s",
10:19:39 INFO - "repository": "",
10:19:39 INFO - "buildername": "Ubuntu HW 12.04 x64 fx-team talos other-e10s",
10:19:39 INFO - "buildid": "20151118091623",
10:19:39 INFO - "slavename": "talos-linux64-ix-045",
10:19:39 INFO - "pgo_build": "False",
10:19:39 INFO - "basedir": "/builds/slave/test",
10:19:39 INFO - "project": "",
10:19:39 INFO - "platform": "ubuntu64_hw",
10:19:39 INFO - "master": "http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/",
10:19:39 INFO - "slavebuilddir": "test",
10:19:39 INFO - "scheduler": "tests-fx-team-linux64-talos",
10:19:39 INFO - "branch": "fx-team",
10:19:39 INFO - "repo_path": "integration/fx-team",
10:19:39 INFO - "stage_platform": "linux64",
10:19:39 INFO - "builduid": "28474222b74b4731a603f3978a06f218",
10:19:39 INFO - "revision": "1d6ba006a526d17294369eed770a9a0ce2794bde"
10:19:39 INFO - },
10:19:39 INFO - "sourcestamp": {
10:19:39 INFO - "repository": "",
10:19:39 INFO - "hasPatch": false,
10:19:39 INFO - "project": "",
10:19:39 INFO - "branch": "fx-team-linux64-talos",
10:19:39 INFO - "changes": [
10:19:39 INFO - {
10:19:39 INFO - "category": null,
10:19:39 INFO - "files": [
10:19:39 INFO - {
10:19:39 INFO - "url": null,
10:19:39 INFO - "name": "https://queue.taskcluster.net/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2"
10:19:39 INFO - }
10:19:39 INFO - ],
10:19:39 INFO - "repository": "",
10:19:39 INFO - "rev": "1d6ba006a526d17294369eed770a9a0ce2794bde",
10:19:39 INFO - "who": "dtownsend@mozilla.com",
10:19:39 INFO - "when": 1447867606,
10:19:39 INFO - "number": 6677891,
10:19:39 INFO - "comments": "Bug 1220911: Remove most of the special casing around experiments. r=rhelmer\n\nExperiments should differ from normal add-ons in a few ways:\n\n* They can always be enabled regardless of compatibility info\n* They default to disabled when installed\n* They cannot be checked for updates\n* They only stay enabled for the lifetime of the current process\n* The UI doesn't give users the ability to enable/disable\n\nThis makes a few changes to keep these differences but remove much of the special casing code for experiments.\n\nBeing able to use regardless of compatibility was mostly fixed by bug 1220198 but I've also removed the redundant override in isCompatible.\n\nPreviously the \"enabled until restart\" feature worked with by not updating the DBAddonInternal object and instead using a hack to make the wrapper still seem enabled. This seems likely to break other code that relies on the state of the DBAddonInternal object so instead we update that as normal and simply don't persist the enabled state to disk.\n\nAlso switch the D",
10:19:39 INFO - "project": "",
10:19:39 INFO - "at": "Wed 18 Nov 2015 09:26:46",
10:19:39 INFO - "branch": "fx-team-linux64-talos",
10:19:39 INFO - "revlink": "",
10:19:39 INFO - "properties": [
10:19:39 INFO - [
10:19:39 INFO - "buildid",
10:19:39 INFO - "20151118091623",
10:19:39 INFO - "Change"
10:19:39 INFO - ],
10:19:39 INFO - [
10:19:39 INFO - "builduid",
10:19:39 INFO - "28474222b74b4731a603f3978a06f218",
10:19:39 INFO - "Change"
10:19:39 INFO - ],
10:19:39 INFO - [
10:19:39 INFO - "pgo_build",
10:19:39 INFO - "False",
10:19:39 INFO - "Change"
10:19:39 INFO - ]
10:19:39 INFO - ],
10:19:39 INFO - "revision": "1d6ba006a526d17294369eed770a9a0ce2794bde"
10:19:39 INFO - }
10:19:39 INFO - ],
10:19:39 INFO - "revision": "1d6ba006a526d17294369eed770a9a0ce2794bde"
10:19:39 INFO - }
10:19:39 INFO - }
10:19:39 INFO - Found installer url https://queue.taskcluster.net/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2.
10:19:39 INFO - Running post-action listener: _resource_record_post_action
10:19:39 INFO - #####
10:19:39 INFO - ##### Running download-and-extract step.
10:19:39 INFO - #####
10:19:39 INFO - Running pre-action listener: _resource_record_pre_action
10:19:39 INFO - Running main action method: download_and_extract
10:19:39 INFO - mkdir: /builds/slave/test/build/tests
10:19:39 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:19:39 INFO - https://queue.taskcluster.net/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/test_packages.json matches https://queue.taskcluster.net
10:19:39 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/test_packages.json
10:19:39 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/test_packages.json
10:19:39 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/test_packages.json to /builds/slave/test/build/test_packages.json
10:19:39 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/test_packages.json', 'file_name': '/builds/slave/test/build/test_packages.json'}, attempt #1
10:19:39 INFO - Downloaded 1302 bytes.
10:19:39 INFO - Reading from file /builds/slave/test/build/test_packages.json
10:19:39 INFO - Using the following test package requirements:
10:19:39 INFO - {u'common': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'],
10:19:39 INFO - u'cppunittest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
10:19:39 INFO - u'firefox-45.0a1.en-US.linux-x86_64.cppunittest.tests.zip'],
10:19:39 INFO - u'jittest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
10:19:39 INFO - u'jsshell-linux-x86_64.zip'],
10:19:39 INFO - u'mochitest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
10:19:39 INFO - u'firefox-45.0a1.en-US.linux-x86_64.mochitest.tests.zip'],
10:19:39 INFO - u'mozbase': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'],
10:19:39 INFO - u'reftest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
10:19:39 INFO - u'firefox-45.0a1.en-US.linux-x86_64.reftest.tests.zip'],
10:19:39 INFO - u'talos': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
10:19:39 INFO - u'firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip'],
10:19:39 INFO - u'web-platform': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
10:19:39 INFO - u'firefox-45.0a1.en-US.linux-x86_64.web-platform.tests.zip'],
10:19:39 INFO - u'webapprt': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'],
10:19:39 INFO - u'xpcshell': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip',
10:19:39 INFO - u'firefox-45.0a1.en-US.linux-x86_64.xpcshell.tests.zip']}
10:19:39 INFO - Downloading packages: [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'] for test suite category: common
10:19:39 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:19:39 INFO - https://queue.taskcluster.net/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip matches https://queue.taskcluster.net
10:19:39 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
10:19:39 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
10:19:39 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip to /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
10:19:39 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 'file_name': u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'}, attempt #1
10:19:41 INFO - Downloaded 21291363 bytes.
10:19:41 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'] in /builds/slave/test/build/tests
10:19:41 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
10:19:41 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'] with output_timeout 1760
10:19:42 INFO - Return code: 0
10:19:42 INFO - Downloading packages: [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', u'firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip'] for test suite category: talos
10:19:42 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:19:42 INFO - https://queue.taskcluster.net/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip matches https://queue.taskcluster.net
10:19:42 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
10:19:42 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
10:19:42 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip to /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
10:19:42 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 'file_name': u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'}, attempt #1
10:19:43 INFO - Downloaded 21291363 bytes.
10:19:43 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'] in /builds/slave/test/build/tests
10:19:43 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip
10:19:43 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'] with output_timeout 1760
10:19:44 INFO - Return code: 0
10:19:44 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:19:44 INFO - https://queue.taskcluster.net/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip matches https://queue.taskcluster.net
10:19:44 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip
10:19:44 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip
10:19:44 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip to /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip
10:19:44 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip', 'file_name': u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip'}, attempt #1
10:19:45 INFO - Downloaded 11130997 bytes.
10:19:45 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip'] in /builds/slave/test/build/tests
10:19:45 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip
10:19:45 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip'] with output_timeout 1760
10:19:45 INFO - Return code: 0
10:19:45 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:19:45 INFO - https://queue.taskcluster.net/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 matches https://queue.taskcluster.net
10:19:45 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2
10:19:45 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2
10:19:45 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 to /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2
10:19:45 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2', 'file_name': '/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2'}, attempt #1
10:19:46 INFO - Downloaded 55666594 bytes.
10:19:46 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2
10:19:46 INFO - mkdir: /builds/slave/test/properties
10:19:46 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url
10:19:46 INFO - Writing to file /builds/slave/test/properties/build_url
10:19:46 INFO - Contents:
10:19:46 INFO - build_url:https://queue.taskcluster.net/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2
10:19:46 INFO - Running post-action listener: _resource_record_post_action
10:19:46 INFO - Running post-action listener: set_extra_try_arguments
10:19:46 INFO - #####
10:19:46 INFO - ##### Running populate-webroot step.
10:19:46 INFO - #####
10:19:46 INFO - Running pre-action listener: _resource_record_pre_action
10:19:46 INFO - Running main action method: populate_webroot
10:19:46 INFO - {'extra_options': {'android': ['--apkPath=%(apk_path)s']},
10:19:46 INFO - 'mobile-suites': {'remote-tp4m_nochrome': {'tests': ['tp4m']},
10:19:46 INFO - 'remote-trobocheck2': {'talos_options': ['--fennecIDs',
10:19:46 INFO - '../fennec_ids.txt'],
10:19:46 INFO - 'tests': ['tcheck2']},
10:19:46 INFO - 'remote-tsvgx': {'talos_options': ['--noChrome',
10:19:46 INFO - '--tppagecycles',
10:19:46 INFO - '7'],
10:19:46 INFO - 'tests': ['tsvgm']}},
10:19:46 INFO - 'suites': {'chromez': {'tests': ['tresize', 'tcanvasmark']},
10:19:46 INFO - 'chromez-e10s': {'talos_options': ['--e10s'],
10:19:46 INFO - 'tests': ['tresize', 'tcanvasmark']},
10:19:46 INFO - 'dromaeojs': {'tests': ['dromaeo_css', 'kraken', 'v8_7']},
10:19:46 INFO - 'dromaeojs-e10s': {'talos_options': ['--e10s'],
10:19:46 INFO - 'tests': ['dromaeo_css', 'kraken', 'v8_7']},
10:19:46 INFO - 'g1': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
10:19:46 INFO - 'tests': ['tp5o_scroll', 'glterrain']},
10:19:46 INFO - 'g1-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
10:19:46 INFO - 'talos_options': ['--e10s'],
10:19:46 INFO - 'tests': ['tp5o_scroll', 'glterrain']},
10:19:46 INFO - 'g2': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
10:19:46 INFO - 'tests': ['damp', 'tps']},
10:19:46 INFO - 'g2-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
10:19:46 INFO - 'talos_options': ['--e10s'],
10:19:46 INFO - 'tests': ['damp', 'tps']},
10:19:46 INFO - 'g3': {'tests': ['dromaeo_dom']},
10:19:46 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']},
10:19:46 INFO - 'other': {'tests': ['a11yr',
10:19:46 INFO - 'ts_paint',
10:19:46 INFO - 'tpaint',
10:19:46 INFO - 'sessionrestore',
10:19:46 INFO - 'sessionrestore_no_auto_restore']},
10:19:46 INFO - 'other-e10s': {'talos_options': ['--e10s'],
10:19:46 INFO - 'tests': ['a11yr',
10:19:46 INFO - 'ts_paint',
10:19:46 INFO - 'tpaint',
10:19:46 INFO - 'sessionrestore',
10:19:46 INFO - 'sessionrestore_no_auto_restore']},
10:19:46 INFO - 'other-e10s_l64': {'talos_options': ['--e10s'],
10:19:46 INFO - 'tests': ['a11yr',
10:19:46 INFO - 'ts_paint',
10:19:46 INFO - 'tpaint',
10:19:46 INFO - 'sessionrestore',
10:19:46 INFO - 'sessionrestore_no_auto_restore']},
10:19:46 INFO - 'other-e10s_nol64': {'talos_options': ['--e10s'],
10:19:46 INFO - 'tests': ['a11yr',
10:19:46 INFO - 'ts_paint',
10:19:46 INFO - 'tpaint',
10:19:46 INFO - 'sessionrestore',
10:19:46 INFO - 'sessionrestore_no_auto_restore']},
10:19:46 INFO - 'other_l64': {'tests': ['a11yr',
10:19:46 INFO - 'ts_paint',
10:19:46 INFO - 'tpaint',
10:19:46 INFO - 'sessionrestore',
10:19:46 INFO - 'sessionrestore_no_auto_restore']},
10:19:46 INFO - 'other_nol64': {'tests': ['a11yr',
10:19:46 INFO - 'ts_paint',
10:19:46 INFO - 'tpaint',
10:19:46 INFO - 'sessionrestore',
10:19:46 INFO - 'sessionrestore_no_auto_restore']},
10:19:46 INFO - 'svgr': {'tests': ['tsvgx',
10:19:46 INFO - 'tsvgr_opacity',
10:19:46 INFO - 'tart',
10:19:46 INFO - 'tscrollx',
10:19:46 INFO - 'cart']},
10:19:46 INFO - 'svgr-e10s': {'talos_options': ['--e10s'],
10:19:46 INFO - 'tests': ['tsvgx',
10:19:46 INFO - 'tsvgr_opacity',
10:19:46 INFO - 'tart',
10:19:46 INFO - 'tscrollx',
10:19:46 INFO - 'cart']},
10:19:46 INFO - 'tp5o': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
10:19:46 INFO - 'tests': ['tp5o']},
10:19:46 INFO - 'tp5o-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
10:19:46 INFO - 'talos_options': ['--e10s'],
10:19:46 INFO - 'tests': ['tp5o']},
10:19:46 INFO - 'xperf': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
10:19:46 INFO - 'talos_options': ['--xperf_path',
10:19:46 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'],
10:19:46 INFO - 'tests': ['tp5n']},
10:19:46 INFO - 'xperf-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
10:19:46 INFO - 'talos_options': ['--e10s',
10:19:46 INFO - '--xperf_path',
10:19:46 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'],
10:19:46 INFO - 'tests': ['tp5n']}},
10:19:46 INFO - 'talos.zip': {'path': '',
10:19:46 INFO - 'url': 'http://talos-bundles.pvt.build.mozilla.org/zips/talos.a6052c33d420.zip'}}
10:19:46 INFO - Running post-action listener: _resource_record_post_action
10:19:46 INFO - #####
10:19:46 INFO - ##### Running create-virtualenv step.
10:19:46 INFO - #####
10:19:46 INFO - Running pre-action listener: _resource_record_pre_action
10:19:46 INFO - Running main action method: create_virtualenv
10:19:46 INFO - Creating virtualenv /builds/slave/test/build/venv
10:19:46 INFO - Running command: ['/tools/buildbot/bin/python', '/tools/misc-python/virtualenv.py', '--no-site-packages', '--distribute', '/builds/slave/test/build/venv'] in /builds/slave/test/build
10:19:46 INFO - Copy/paste: /tools/buildbot/bin/python /tools/misc-python/virtualenv.py --no-site-packages --distribute /builds/slave/test/build/venv
10:19:47 INFO - The --no-site-packages flag is deprecated; it is now the default behavior.
10:19:47 INFO - Using real prefix '/usr'
10:19:47 INFO - New python executable in /builds/slave/test/build/venv/bin/python
10:19:47 INFO - Installing distribute.............................................................................................................................................................................................done.
10:19:49 INFO - Installing pip.................done.
10:19:49 INFO - Return code: 0
10:19:49 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv
10:19:49 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:19:49 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
10:19:49 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:19:49 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:19:49 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
10:19:49 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:19:49 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'pip>=1.5']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fcad9a18c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x21516c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2202900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2248b70>, '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 0x2299dc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x229a250>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1
10:19:49 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'pip>=1.5'] in /builds/slave/test/build
10:19:49 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub pip>=1.5
10:19:49 INFO - Using env: {'DISPLAY': ':0',
10:19:49 INFO - 'HOME': '/home/cltbld',
10:19:49 INFO - 'LANG': 'en_US.UTF-8',
10:19:49 INFO - 'LANGUAGE': 'en_US:en',
10:19:49 INFO - 'LOGNAME': 'cltbld',
10:19:49 INFO - 'MAIL': '/var/mail/cltbld',
10:19:49 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
10:19:49 INFO - 'MOZ_NO_REMOTE': '1',
10:19:49 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
10:19:49 INFO - 'NO_EM_RESTART': '1',
10:19:49 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
10:19:49 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
10:19:49 INFO - 'PWD': '/builds/slave/test',
10:19:49 INFO - 'SHELL': '/bin/bash',
10:19:49 INFO - 'SHLVL': '1',
10:19:49 INFO - 'TERM': 'linux',
10:19:49 INFO - 'TMOUT': '86400',
10:19:49 INFO - 'USER': 'cltbld',
10:19:49 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883',
10:19:49 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
10:19:49 INFO - '_': '/tools/buildbot/bin/python'}
10:19:49 INFO - Ignoring indexes: https://pypi.python.org/simple/
10:19:49 INFO - Requirement already satisfied (use --upgrade to upgrade): pip>=1.5 in ./venv/lib/python2.7/site-packages/pip-1.5.5-py2.7.egg
10:19:49 INFO - Cleaning up...
10:19:49 INFO - Return code: 0
10:19:49 INFO - Installing psutil>=0.7.1 into virtualenv /builds/slave/test/build/venv
10:19:49 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:19:49 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
10:19:49 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:19:49 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:19:49 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
10:19:49 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:19:49 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '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 0x7fcad9a18c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x21516c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2202900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2248b70>, '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 0x2299dc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x229a250>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1
10:19:49 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'psutil>=0.7.1'] in /builds/slave/test/build
10:19:49 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub psutil>=0.7.1
10:19:49 INFO - Using env: {'DISPLAY': ':0',
10:19:49 INFO - 'HOME': '/home/cltbld',
10:19:49 INFO - 'LANG': 'en_US.UTF-8',
10:19:49 INFO - 'LANGUAGE': 'en_US:en',
10:19:49 INFO - 'LOGNAME': 'cltbld',
10:19:49 INFO - 'MAIL': '/var/mail/cltbld',
10:19:49 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
10:19:49 INFO - 'MOZ_NO_REMOTE': '1',
10:19:49 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
10:19:49 INFO - 'NO_EM_RESTART': '1',
10:19:49 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
10:19:49 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
10:19:49 INFO - 'PWD': '/builds/slave/test',
10:19:49 INFO - 'SHELL': '/bin/bash',
10:19:49 INFO - 'SHLVL': '1',
10:19:49 INFO - 'TERM': 'linux',
10:19:49 INFO - 'TMOUT': '86400',
10:19:49 INFO - 'USER': 'cltbld',
10:19:49 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883',
10:19:49 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
10:19:49 INFO - '_': '/tools/buildbot/bin/python'}
10:19:49 INFO - Ignoring indexes: https://pypi.python.org/simple/
10:19:49 INFO - Downloading/unpacking psutil>=0.7.1
10:19:49 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available
10:19:49 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available
10:19:49 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available
10:19:49 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available
10:19:49 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available
10:19:49 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available
10:19:51 INFO - Creating supposed download cache at /builds/slave/test/build/venv/cache
10:19:51 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fpsutil-3.1.1.tar.gz
10:19:51 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/psutil/setup.py) egg_info for package psutil
10:19:51 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build'
10:19:51 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects
...
10:19:51 INFO - Installing collected packages: psutil
10:19:51 INFO - Running setup.py install for psutil
10:19:51 INFO - building 'psutil._psutil_linux' extension
10:19:51 INFO - gcc -pthread -fno-strict-aliasing -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -fPIC -DPSUTIL_VERSION=311 -I/usr/include/python2.7 -c psutil/_psutil_linux.c -o build/temp.linux-x86_64-2.7/psutil/_psutil_linux.o
10:19:51 INFO - gcc -pthread -shared -Wl,-O1 -Wl,-Bsymbolic-functions -Wl,-Bsymbolic-functions -Wl,-z,relro build/temp.linux-x86_64-2.7/psutil/_psutil_linux.o -o build/lib.linux-x86_64-2.7/psutil/_psutil_linux.so
10:19:52 INFO - building 'psutil._psutil_posix' extension
10:19:52 INFO - gcc -pthread -fno-strict-aliasing -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -fPIC -I/usr/include/python2.7 -c psutil/_psutil_posix.c -o build/temp.linux-x86_64-2.7/psutil/_psutil_posix.o
10:19:52 INFO - gcc -pthread -shared -Wl,-O1 -Wl,-Bsymbolic-functions -Wl,-Bsymbolic-functions -Wl,-z,relro build/temp.linux-x86_64-2.7/psutil/_psutil_posix.o -o build/lib.linux-x86_64-2.7/psutil/_psutil_posix.so
10:19:52 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build'
10:19:52 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ...
10:19:52 INFO - Successfully installed psutil
10:19:52 INFO - Cleaning up...
10:19:52 INFO - Return code: 0
10:19:52 INFO - Installing mozsystemmonitor==0.0.0 into virtualenv /builds/slave/test/build/venv
10:19:52 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:19:52 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
10:19:52 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:19:52 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:19:52 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
10:19:52 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:19:52 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 0x7fcad9a18c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x21516c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2202900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2248b70>, '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 0x2299dc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x229a250>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1
10:19:52 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'mozsystemmonitor==0.0.0'] in /builds/slave/test/build
10:19:52 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub mozsystemmonitor==0.0.0
10:19:52 INFO - Using env: {'DISPLAY': ':0',
10:19:52 INFO - 'HOME': '/home/cltbld',
10:19:52 INFO - 'LANG': 'en_US.UTF-8',
10:19:52 INFO - 'LANGUAGE': 'en_US:en',
10:19:52 INFO - 'LOGNAME': 'cltbld',
10:19:52 INFO - 'MAIL': '/var/mail/cltbld',
10:19:52 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
10:19:52 INFO - 'MOZ_NO_REMOTE': '1',
10:19:52 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
10:19:52 INFO - 'NO_EM_RESTART': '1',
10:19:52 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
10:19:52 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
10:19:52 INFO - 'PWD': '/builds/slave/test',
10:19:52 INFO - 'SHELL': '/bin/bash',
10:19:52 INFO - 'SHLVL': '1',
10:19:52 INFO - 'TERM': 'linux',
10:19:52 INFO - 'TMOUT': '86400',
10:19:52 INFO - 'USER': 'cltbld',
10:19:52 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883',
10:19:52 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
10:19:52 INFO - '_': '/tools/buildbot/bin/python'}
10:19:52 INFO - Ignoring indexes: https://pypi.python.org/simple/
10:19:52 INFO - Downloading/unpacking mozsystemmonitor==0.0.0
10:19:52 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available
10:19:52 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available
10:19:52 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available
10:19:52 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available
10:19:52 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available
10:19:52 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available
10:19:54 INFO - Downloading mozsystemmonitor-0.0.tar.gz
10:19:54 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fmozsystemmonitor-0.0.tar.gz
10:19:54 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/mozsystemmonitor/setup.py) egg_info for package mozsystemmonitor
10:19:54 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=0.7.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.0.0)
10:19:54 INFO - Installing collected packages: mozsystemmonitor
10:19:54 INFO - Running setup.py install for mozsystemmonitor
10:19:54 INFO - Successfully installed mozsystemmonitor
10:19:54 INFO - Cleaning up...
10:19:54 INFO - Return code: 0
10:19:54 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv
10:19:54 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:19:54 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
10:19:54 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:19:54 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:19:54 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
10:19:54 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:19:54 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 0x7fcad9a18c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x21516c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2202900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2248b70>, '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 0x2299dc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x229a250>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1
10:19:54 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'blobuploader==1.2.4'] in /builds/slave/test/build
10:19:54 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub blobuploader==1.2.4
10:19:54 INFO - Using env: {'DISPLAY': ':0',
10:19:54 INFO - 'HOME': '/home/cltbld',
10:19:54 INFO - 'LANG': 'en_US.UTF-8',
10:19:54 INFO - 'LANGUAGE': 'en_US:en',
10:19:54 INFO - 'LOGNAME': 'cltbld',
10:19:54 INFO - 'MAIL': '/var/mail/cltbld',
10:19:54 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
10:19:54 INFO - 'MOZ_NO_REMOTE': '1',
10:19:54 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
10:19:54 INFO - 'NO_EM_RESTART': '1',
10:19:54 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
10:19:54 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
10:19:54 INFO - 'PWD': '/builds/slave/test',
10:19:54 INFO - 'SHELL': '/bin/bash',
10:19:54 INFO - 'SHLVL': '1',
10:19:54 INFO - 'TERM': 'linux',
10:19:54 INFO - 'TMOUT': '86400',
10:19:54 INFO - 'USER': 'cltbld',
10:19:54 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883',
10:19:54 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
10:19:54 INFO - '_': '/tools/buildbot/bin/python'}
10:19:54 INFO - Ignoring indexes: https://pypi.python.org/simple/
10:19:54 INFO - Downloading/unpacking blobuploader==1.2.4
10:19:54 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available
10:19:54 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available
10:19:54 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available
10:19:54 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available
10:19:54 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available
10:19:54 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available
10:19:56 INFO - Downloading blobuploader-1.2.4.tar.gz
10:19:56 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fblobuploader-1.2.4.tar.gz
10:19:56 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blobuploader/setup.py) egg_info for package blobuploader
10:19:56 INFO - Downloading/unpacking requests==1.2.3. (from blobuploader==1.2.4)
10:19:56 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available
10:19:56 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available
10:19:56 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available
10:19:56 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available
10:19:56 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available
10:19:56 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available
10:19:56 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Frequests-1.2.3.tar.gz
10:19:56 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests
10:19:56 INFO - Downloading/unpacking docopt==0.6.1 (from blobuploader==1.2.4)
10:19:56 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available
10:19:56 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available
10:19:56 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available
10:19:56 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available
10:19:56 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available
10:19:56 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available
10:19:56 INFO - Downloading docopt-0.6.1.tar.gz
10:19:56 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fdocopt-0.6.1.tar.gz
10:19:56 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/docopt/setup.py) egg_info for package docopt
10:19:56 INFO - Installing collected packages: blobuploader, requests, docopt
10:19:56 INFO - Running setup.py install for blobuploader
10:19:57 INFO - changing mode of build/scripts-2.7/blobberc.py from 664 to 775
10:19:57 INFO - changing mode of /builds/slave/test/build/venv/bin/blobberc.py to 775
10:19:57 INFO - Running setup.py install for requests
10:19:57 INFO - Running setup.py install for docopt
10:19:57 INFO - Successfully installed blobuploader requests docopt
10:19:57 INFO - Cleaning up...
10:19:57 INFO - Return code: 0
10:19:57 INFO - Installing None into virtualenv /builds/slave/test/build/venv
10:19:57 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:19:57 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
10:19:57 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:19:57 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:19:57 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
10:19:57 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:19:57 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 0x7fcad9a18c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x21516c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2202900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2248b70>, '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 0x2299dc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x229a250>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build/tests/config', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1
10:19:57 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/config
10:19:57 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --no-deps --download-cache /builds/slave/test/build/venv/cache --timeout 120 -r /builds/slave/test/build/tests/config/mozbase_requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub
10:19:57 INFO - Using env: {'DISPLAY': ':0',
10:19:57 INFO - 'HOME': '/home/cltbld',
10:19:57 INFO - 'LANG': 'en_US.UTF-8',
10:19:57 INFO - 'LANGUAGE': 'en_US:en',
10:19:57 INFO - 'LOGNAME': 'cltbld',
10:19:57 INFO - 'MAIL': '/var/mail/cltbld',
10:19:57 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
10:19:57 INFO - 'MOZ_NO_REMOTE': '1',
10:19:57 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
10:19:57 INFO - 'NO_EM_RESTART': '1',
10:19:57 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
10:19:57 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
10:19:57 INFO - 'PWD': '/builds/slave/test',
10:19:57 INFO - 'SHELL': '/bin/bash',
10:19:57 INFO - 'SHLVL': '1',
10:19:57 INFO - 'TERM': 'linux',
10:19:57 INFO - 'TMOUT': '86400',
10:19:57 INFO - 'USER': 'cltbld',
10:19:57 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883',
10:19:57 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
10:19:57 INFO - '_': '/tools/buildbot/bin/python'}
10:19:57 INFO - Ignoring indexes: https://pypi.python.org/simple/
10:19:57 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser
10:19:57 INFO - Running setup.py (path:/tmp/pip-duffhD-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser
10:19:57 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash
10:19:57 INFO - Running setup.py (path:/tmp/pip-zoIVwU-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash
10:19:57 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug
10:19:57 INFO - Running setup.py (path:/tmp/pip-5a6CkH-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug
10:19:57 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice
10:19:57 INFO - Running setup.py (path:/tmp/pip-ltp60O-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice
10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile
10:19:58 INFO - Running setup.py (path:/tmp/pip-6og9Yc-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile
10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd
10:19:58 INFO - Running setup.py (path:/tmp/pip-pzT_P0-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd
10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo
10:19:58 INFO - Running setup.py (path:/tmp/pip-MvRsGI-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo
10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall
10:19:58 INFO - Running setup.py (path:/tmp/pip-MXP9pP-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall
10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak
10:19:58 INFO - Running setup.py (path:/tmp/pip-4cCXok-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak
10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog
10:19:58 INFO - Running setup.py (path:/tmp/pip-9tlR8L-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog
10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork
10:19:58 INFO - Running setup.py (path:/tmp/pip-XEOXzj-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork
10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess
10:19:58 INFO - Running setup.py (path:/tmp/pip-SQOyIR-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess
10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile
10:19:58 INFO - Running setup.py (path:/tmp/pip-6O7Jwn-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile
10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner
10:19:58 INFO - Running setup.py (path:/tmp/pip-dsEyVW-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner
10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot
10:19:58 INFO - Running setup.py (path:/tmp/pip-5tn1DY-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot
10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest
10:19:58 INFO - Running setup.py (path:/tmp/pip-M6FDm_-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest
10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion
10:19:58 INFO - Running setup.py (path:/tmp/pip-pg6eS3-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion
10:19:58 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion
10:19:58 INFO - Running setup.py install for manifestparser
10:19:59 INFO - Installing manifestparser script to /builds/slave/test/build/venv/bin
10:19:59 INFO - Running setup.py install for mozcrash
10:19:59 INFO - Running setup.py install for mozdebug
10:19:59 INFO - Running setup.py install for mozdevice
10:19:59 INFO - Installing sutini script to /builds/slave/test/build/venv/bin
10:19:59 INFO - Installing dm script to /builds/slave/test/build/venv/bin
10:19:59 INFO - Running setup.py install for mozfile
10:19:59 INFO - Running setup.py install for mozhttpd
10:19:59 INFO - Installing mozhttpd script to /builds/slave/test/build/venv/bin
10:19:59 INFO - Running setup.py install for mozinfo
10:19:59 INFO - Installing mozinfo script to /builds/slave/test/build/venv/bin
10:19:59 INFO - Running setup.py install for mozInstall
10:19:59 INFO - Installing moz_remove_from_system script to /builds/slave/test/build/venv/bin
10:19:59 INFO - Installing mozuninstall script to /builds/slave/test/build/venv/bin
10:19:59 INFO - Installing mozinstall script to /builds/slave/test/build/venv/bin
10:19:59 INFO - Installing moz_add_to_system script to /builds/slave/test/build/venv/bin
10:19:59 INFO - Running setup.py install for mozleak
10:19:59 INFO - Running setup.py install for mozlog
10:19:59 INFO - Installing structlog script to /builds/slave/test/build/venv/bin
10:20:00 INFO - Running setup.py install for moznetwork
10:20:00 INFO - Installing moznetwork script to /builds/slave/test/build/venv/bin
10:20:00 INFO - Running setup.py install for mozprocess
10:20:00 INFO - Running setup.py install for mozprofile
10:20:00 INFO - Installing mozprofile script to /builds/slave/test/build/venv/bin
10:20:00 INFO - Installing diff-profiles script to /builds/slave/test/build/venv/bin
10:20:00 INFO - Installing view-profile script to /builds/slave/test/build/venv/bin
10:20:00 INFO - Running setup.py install for mozrunner
10:20:00 INFO - Installing mozrunner script to /builds/slave/test/build/venv/bin
10:20:00 INFO - Running setup.py install for mozscreenshot
10:20:00 INFO - Running setup.py install for moztest
10:20:00 INFO - Running setup.py install for mozversion
10:20:00 INFO - Installing mozversion script to /builds/slave/test/build/venv/bin
10:20:00 INFO - Successfully installed manifestparser mozcrash mozdebug mozdevice mozfile mozhttpd mozinfo mozInstall mozleak mozlog moznetwork mozprocess mozprofile mozrunner mozscreenshot moztest mozversion
10:20:00 INFO - Cleaning up...
10:20:00 INFO - Return code: 0
10:20:00 INFO - Installing None into virtualenv /builds/slave/test/build/venv
10:20:00 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:20:00 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
10:20:00 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:20:00 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:20:00 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
10:20:00 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:20:00 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 0x7fcad9a18c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x21516c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2202900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2248b70>, '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 0x2299dc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x229a250>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build/tests/config', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1
10:20:00 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/config
10:20:00 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 -r /builds/slave/test/build/tests/config/mozbase_requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub
10:20:00 INFO - Using env: {'DISPLAY': ':0',
10:20:00 INFO - 'HOME': '/home/cltbld',
10:20:00 INFO - 'LANG': 'en_US.UTF-8',
10:20:00 INFO - 'LANGUAGE': 'en_US:en',
10:20:00 INFO - 'LOGNAME': 'cltbld',
10:20:00 INFO - 'MAIL': '/var/mail/cltbld',
10:20:00 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
10:20:00 INFO - 'MOZ_NO_REMOTE': '1',
10:20:00 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
10:20:00 INFO - 'NO_EM_RESTART': '1',
10:20:00 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
10:20:00 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
10:20:00 INFO - 'PWD': '/builds/slave/test',
10:20:00 INFO - 'SHELL': '/bin/bash',
10:20:00 INFO - 'SHLVL': '1',
10:20:00 INFO - 'TERM': 'linux',
10:20:00 INFO - 'TMOUT': '86400',
10:20:00 INFO - 'USER': 'cltbld',
10:20:00 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883',
10:20:00 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
10:20:00 INFO - '_': '/tools/buildbot/bin/python'}
10:20:00 INFO - Ignoring indexes: https://pypi.python.org/simple/
10:20:00 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser
10:20:00 INFO - Running setup.py (path:/tmp/pip-c7qutr-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser
10:20:01 INFO - Requirement already satisfied (use --upgrade to upgrade): manifestparser==1.1 from file:///builds/slave/test/build/tests/mozbase/manifestparser in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 1))
10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash
10:20:01 INFO - Running setup.py (path:/tmp/pip-BhrsEy-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash
10:20:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash==0.16 from file:///builds/slave/test/build/tests/mozbase/mozcrash in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2))
10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug
10:20:01 INFO - Running setup.py (path:/tmp/pip-FxzEOY-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug
10:20:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdebug==0.1 from file:///builds/slave/test/build/tests/mozbase/mozdebug in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 3))
10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice
10:20:01 INFO - Running setup.py (path:/tmp/pip-3qHW01-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice
10:20:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdevice==0.47 from file:///builds/slave/test/build/tests/mozbase/mozdevice in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4))
10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile
10:20:01 INFO - Running setup.py (path:/tmp/pip-QeIRIQ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile
10:20:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile==1.2 from file:///builds/slave/test/build/tests/mozbase/mozfile in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 5))
10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd
10:20:01 INFO - Running setup.py (path:/tmp/pip-KCn_JJ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd
10:20:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd==0.7 from file:///builds/slave/test/build/tests/mozbase/mozhttpd in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 6))
10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo
10:20:01 INFO - Running setup.py (path:/tmp/pip-nIpMOC-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo
10:20:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo==0.9 from file:///builds/slave/test/build/tests/mozbase/mozinfo in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 7))
10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall
10:20:01 INFO - Running setup.py (path:/tmp/pip-IsOWmd-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall
10:20:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozInstall==1.12 from file:///builds/slave/test/build/tests/mozbase/mozinstall in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 8))
10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak
10:20:01 INFO - Running setup.py (path:/tmp/pip-SCBwwj-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak
10:20:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozleak==0.1 from file:///builds/slave/test/build/tests/mozbase/mozleak in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 9))
10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog
10:20:01 INFO - Running setup.py (path:/tmp/pip-GW1A0t-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog
10:20:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog==3.0 from file:///builds/slave/test/build/tests/mozbase/mozlog in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10))
10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork
10:20:01 INFO - Running setup.py (path:/tmp/pip-wga2dh-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork
10:20:01 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork==0.27 from file:///builds/slave/test/build/tests/mozbase/moznetwork in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 11))
10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess
10:20:01 INFO - Running setup.py (path:/tmp/pip-Y0QL7j-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess
10:20:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess==0.22 from file:///builds/slave/test/build/tests/mozbase/mozprocess in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 12))
10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile
10:20:01 INFO - Running setup.py (path:/tmp/pip-SDQC51-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile
10:20:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile==0.27 from file:///builds/slave/test/build/tests/mozbase/mozprofile in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 13))
10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner
10:20:01 INFO - Running setup.py (path:/tmp/pip-POCZe8-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner
10:20:02 INFO - Requirement already satisfied (use --upgrade to upgrade): mozrunner==6.11 from file:///builds/slave/test/build/tests/mozbase/mozrunner in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 14))
10:20:02 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot
10:20:02 INFO - Running setup.py (path:/tmp/pip-LlPyAW-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot
10:20:02 INFO - Requirement already satisfied (use --upgrade to upgrade): mozscreenshot==0.1 from file:///builds/slave/test/build/tests/mozbase/mozscreenshot in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 15))
10:20:02 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest
10:20:02 INFO - Running setup.py (path:/tmp/pip-G_PqZ4-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest
10:20:02 INFO - Requirement already satisfied (use --upgrade to upgrade): moztest==0.7 from file:///builds/slave/test/build/tests/mozbase/moztest in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 16))
10:20:02 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion
10:20:02 INFO - Running setup.py (path:/tmp/pip-jIm9KN-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion
10:20:02 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion==1.4 from file:///builds/slave/test/build/tests/mozbase/mozversion in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 17))
10:20:02 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozcrash==0.16->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2))
10:20:02 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozcrash==0.16->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2))
10:20:02 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozdebug==0.1->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 3))
10:20:02 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork>=0.24 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozdevice==0.47->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4))
10:20:02 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.19 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozdevice==0.47->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4))
10:20:02 INFO - Downloading/unpacking blessings>=1.3 (from mozlog==3.0->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10))
10:20:02 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available
10:20:02 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available
10:20:02 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available
10:20:02 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available
10:20:02 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available
10:20:02 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available
10:20:03 INFO - Downloading blessings-1.5.1.tar.gz
10:20:03 INFO - Storing download in cache at /builds/slave/test/build/venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fblessings-1.5.1.tar.gz
10:20:03 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blessings/setup.py) egg_info for package blessings
10:20:03 INFO - Installing collected packages: blessings
10:20:03 INFO - Running setup.py install for blessings
10:20:04 INFO - Successfully installed blessings
10:20:04 INFO - Cleaning up...
10:20:04 INFO - Return code: 0
10:20:04 INFO - Done creating virtualenv /builds/slave/test/build/venv.
10:20:04 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze']
10:20:04 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze
10:20:04 INFO - Reading from file tmpfile_stdout
10:20:04 INFO - Current package versions:
10:20:04 INFO - argparse == 1.2.1
10:20:04 INFO - blessings == 1.5.1
10:20:04 INFO - blobuploader == 1.2.4
10:20:04 INFO - docopt == 0.6.1
10:20:04 INFO - manifestparser == 1.1
10:20:04 INFO - mozInstall == 1.12
10:20:04 INFO - mozcrash == 0.16
10:20:04 INFO - mozdebug == 0.1
10:20:04 INFO - mozdevice == 0.47
10:20:04 INFO - mozfile == 1.2
10:20:04 INFO - mozhttpd == 0.7
10:20:04 INFO - mozinfo == 0.9
10:20:04 INFO - mozleak == 0.1
10:20:04 INFO - mozlog == 3.0
10:20:04 INFO - moznetwork == 0.27
10:20:04 INFO - mozprocess == 0.22
10:20:04 INFO - mozprofile == 0.27
10:20:04 INFO - mozrunner == 6.11
10:20:04 INFO - mozscreenshot == 0.1
10:20:04 INFO - mozsystemmonitor == 0.0
10:20:04 INFO - moztest == 0.7
10:20:04 INFO - mozversion == 1.4
10:20:04 INFO - psutil == 3.1.1
10:20:04 INFO - requests == 1.2.3
10:20:04 INFO - wsgiref == 0.1.2
10:20:04 INFO - Installing None into virtualenv /builds/slave/test/build/venv
10:20:04 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:20:04 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
10:20:04 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:20:04 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:20:04 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
10:20:04 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
10:20:04 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '-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 0x7fcad9a18c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x21516c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2202900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2248b70>, '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 0x2299dc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x229a250>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build/tests/talos', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1
10:20:04 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test/build/tests/talos/requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/talos
10:20:04 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 -r /builds/slave/test/build/tests/talos/requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub
10:20:04 INFO - Using env: {'DISPLAY': ':0',
10:20:04 INFO - 'HOME': '/home/cltbld',
10:20:04 INFO - 'LANG': 'en_US.UTF-8',
10:20:04 INFO - 'LANGUAGE': 'en_US:en',
10:20:04 INFO - 'LOGNAME': 'cltbld',
10:20:04 INFO - 'MAIL': '/var/mail/cltbld',
10:20:04 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
10:20:04 INFO - 'MOZ_NO_REMOTE': '1',
10:20:04 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
10:20:04 INFO - 'NO_EM_RESTART': '1',
10:20:04 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
10:20:04 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
10:20:04 INFO - 'PWD': '/builds/slave/test',
10:20:04 INFO - 'SHELL': '/bin/bash',
10:20:04 INFO - 'SHLVL': '1',
10:20:04 INFO - 'TERM': 'linux',
10:20:04 INFO - 'TMOUT': '86400',
10:20:04 INFO - 'USER': 'cltbld',
10:20:04 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883',
10:20:04 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
10:20:04 INFO - '_': '/tools/buildbot/bin/python'}
10:20:04 INFO - Ignoring indexes: https://pypi.python.org/simple/
10:20:04 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash>=0.15 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 1))
10:20:04 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.2 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 2))
10:20:04 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd>=0.7 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 3))
10:20:04 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo>=0.8 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 4))
10:20:04 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.22 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 5))
10:20:04 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion>=1.3 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 6))
10:20:04 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile>=0.25 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 7))
10:20:04 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 8))
10:20:04 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozcrash>=0.15->-r /builds/slave/test/build/tests/talos/requirements.txt (line 1))
10:20:04 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork>=0.24 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozhttpd>=0.7->-r /builds/slave/test/build/tests/talos/requirements.txt (line 3))
10:20:04 INFO - Requirement already satisfied (use --upgrade to upgrade): blessings>=1.3 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozlog>=3.0->mozcrash>=0.15->-r /builds/slave/test/build/tests/talos/requirements.txt (line 1))
10:20:04 INFO - Cleaning up...
10:20:04 INFO - Return code: 0
10:20:04 INFO - Running post-action listener: _resource_record_post_action
10:20:04 INFO - Running post-action listener: _start_resource_monitoring
10:20:04 INFO - Starting resource monitoring.
10:20:04 INFO - #####
10:20:04 INFO - ##### Running install step.
10:20:04 INFO - #####
10:20:04 INFO - Running pre-action listener: _resource_record_pre_action
10:20:04 INFO - Running main action method: install
10:20:04 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze']
10:20:04 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze
10:20:04 INFO - Reading from file tmpfile_stdout
10:20:04 INFO - Detecting whether we're running mozinstall >=1.0...
10:20:04 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h']
10:20:04 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h
10:20:04 INFO - Reading from file tmpfile_stdout
10:20:04 INFO - Output received:
10:20:04 INFO - Usage: mozinstall [options] installer
10:20:04 INFO - Options:
10:20:04 INFO - -h, --help show this help message and exit
10:20:04 INFO - -d DEST, --destination=DEST
10:20:04 INFO - Directory to install application into. [default:
10:20:04 INFO - "/builds/slave/test"]
10:20:04 INFO - --app=APP Application being installed. [default: firefox]
10:20:04 INFO - mkdir: /builds/slave/test/build/application
10:20:04 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2', '--destination', '/builds/slave/test/build/application']
10:20:04 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 --destination /builds/slave/test/build/application
10:20:19 INFO - Reading from file tmpfile_stdout
10:20:19 INFO - Output received:
10:20:19 INFO - /builds/slave/test/build/application/firefox/firefox
10:20:19 INFO - Running post-action listener: _resource_record_post_action
10:20:19 INFO - #####
10:20:19 INFO - ##### Running run-tests step.
10:20:19 INFO - #####
10:20:19 INFO - Running pre-action listener: _resource_record_pre_action
10:20:19 INFO - Running main action method: run_tests
10:20:19 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version']
10:20:19 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version
10:20:19 INFO - Python 2.7.3
10:20:19 INFO - Return code: 0
10:20:19 INFO - grabbing minidump binary from tooltool
10:20:19 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
10:20:19 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 0x2248b70>, '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 0x2299dc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x229a250>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1
10:20:19 INFO - Running command: ['/tools/tooltool.py', '--url', 'https://api.pub.build.mozilla.org/tooltool/', '--authentication-file', '/builds/relengapi.tok', 'fetch', '-m', '/builds/slave/test/build/tests/config/tooltool-manifests/linux64/releng.manifest', '-o', '-c', '/builds/tooltool_cache'] in /builds/slave/test/build
10:20:19 INFO - Copy/paste: /tools/tooltool.py --url https://api.pub.build.mozilla.org/tooltool/ --authentication-file /builds/relengapi.tok fetch -m /builds/slave/test/build/tests/config/tooltool-manifests/linux64/releng.manifest -o -c /builds/tooltool_cache
10:20:19 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache
10:20:19 INFO - Return code: 0
10:20:19 INFO - Chmoding /builds/slave/test/build/linux64-minidump_stackwalk to 0755
10:20:19 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir
10:20:19 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir
10:20:19 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/linux64-minidump_stackwalk
10:20:19 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir
10:20:19 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/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-045', '--webServer', 'localhost'] in /builds/slave/test/build
10:20:19 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/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.crashreporter-symbols.zip --title talos-linux64-ix-045 --webServer localhost
10:20:19 INFO - Using env: {'DISPLAY': ':0',
10:20:19 INFO - 'HOME': '/home/cltbld',
10:20:19 INFO - 'LANG': 'en_US.UTF-8',
10:20:19 INFO - 'LANGUAGE': 'en_US:en',
10:20:19 INFO - 'LOGNAME': 'cltbld',
10:20:19 INFO - 'MAIL': '/var/mail/cltbld',
10:20:19 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir',
10:20:19 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk',
10:20:19 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
10:20:19 INFO - 'MOZ_NO_REMOTE': '1',
10:20:19 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir',
10:20:19 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
10:20:19 INFO - 'NO_EM_RESTART': '1',
10:20:19 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
10:20:19 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
10:20:19 INFO - 'PWD': '/builds/slave/test',
10:20:19 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos',
10:20:19 INFO - 'SHELL': '/bin/bash',
10:20:19 INFO - 'SHLVL': '1',
10:20:19 INFO - 'TERM': 'linux',
10:20:19 INFO - 'TMOUT': '86400',
10:20:19 INFO - 'USER': 'cltbld',
10:20:19 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883',
10:20:19 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
10:20:19 INFO - '_': '/tools/buildbot/bin/python'}
10:20:19 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/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-045', '--webServer', 'localhost'] with output_timeout 3600
10:20:19 INFO - mozversion INFO | application_buildid: 20151118091623
10:20:19 INFO - mozversion INFO | application_changeset: 1d6ba006a526d17294369eed770a9a0ce2794bde
10:20:19 INFO - mozversion INFO | application_display_name: Nightly
10:20:19 INFO - mozversion INFO | application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384}
10:20:19 INFO - mozversion INFO | application_name: Firefox
10:20:19 INFO - mozversion INFO | application_remotingname: firefox
10:20:19 INFO - mozversion INFO | application_repository: https://hg.mozilla.org/integration/fx-team
10:20:19 INFO - mozversion INFO | application_vendor: Mozilla
10:20:19 INFO - mozversion INFO | application_version: 45.0a1
10:20:19 INFO - mozversion INFO | platform_buildid: 20151118091623
10:20:19 INFO - mozversion INFO | platform_changeset: 1d6ba006a526d17294369eed770a9a0ce2794bde
10:20:19 INFO - mozversion INFO | platform_repository: https://hg.mozilla.org/integration/fx-team
10:20:19 INFO - mozversion INFO | platform_version: 45.0a1
10:20:19 INFO - 2015-11-18 10:20:19,342 DEBUG : using testdate: 1447870819
10:20:19 INFO - 2015-11-18 10:20:19,342 DEBUG : actual date: 1447870819
10:20:19 INFO - 2015-11-18 10:20:19,395 INFO : starting webserver on 'localhost:38426'
10:20:19 INFO - 2015-11-18 10:20:19,396 INFO : Starting test suite talos-linux64-ix-045.e
10:20:19 INFO - 2015-11-18 10:20:19,396 INFO : Starting test a11yr
10:20:19 INFO - 2015-11-18 10:20:19,396 DEBUG : operating with platform_type : linux_
10:20:19 INFO - 2015-11-18 10:20:19,397 INFO : Initialising browser for a11yr test...
10:20:19 INFO - 2015-11-18 10:20:19,411 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVINgwy/profile http://localhost:38426/getInfo.html
10:20:25 INFO - 2015-11-18 10:20:25,063 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
10:20:25 INFO - 2015-11-18 10:20:25,063 DEBUG : BROWSER_OUTPUT: colorDepth:24
10:20:25 INFO - 2015-11-18 10:20:25,063 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697
10:20:25 INFO - 2015-11-18 10:20:25,063 DEBUG : BROWSER_OUTPUT: __metrics
10:20:26 INFO - 2015-11-18 10:20:26,157 INFO : Browser initialized.
10:20:26 INFO - 2015-11-18 10:20:26,158 INFO : Running cycle 1/1 for a11yr test...
10:20:26 INFO - 2015-11-18 10:20:26,158 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVINgwy/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/a11y/a11y.manifest.develop -tpchrome -tpmozafterpaint -tpnoisy -tpcycles 1 -tppagecycles 25
10:20:38 INFO - 2015-11-18 10:20:38,100 DEBUG : BROWSER_OUTPUT: RSS: Main: 141447168
10:20:38 INFO - 2015-11-18 10:20:38,100 DEBUG : BROWSER_OUTPUT:
10:20:39 INFO - 2015-11-18 10:20:39,403 DEBUG : BROWSER_OUTPUT: Cycle 1(1): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:20:39 INFO - 2015-11-18 10:20:39,540 DEBUG : BROWSER_OUTPUT:
10:20:39 INFO - 2015-11-18 10:20:39,540 DEBUG : BROWSER_OUTPUT: (firefox:17760): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed
10:20:39 INFO - 2015-11-18 10:20:39,541 DEBUG : BROWSER_OUTPUT:
10:20:39 INFO - 2015-11-18 10:20:39,541 DEBUG : BROWSER_OUTPUT: (firefox:17760): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed
10:20:39 INFO - 2015-11-18 10:20:39,597 DEBUG : BROWSER_OUTPUT:
10:20:39 INFO - 2015-11-18 10:20:39,597 DEBUG : BROWSER_OUTPUT: (firefox:17760): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed
10:20:40 INFO - 2015-11-18 10:20:40,037 DEBUG : BROWSER_OUTPUT: RSS: Main: 146771968
10:20:40 INFO - 2015-11-18 10:20:40,037 DEBUG : BROWSER_OUTPUT:
10:20:41 INFO - 2015-11-18 10:20:41,430 DEBUG : BROWSER_OUTPUT: Cycle 1(2): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:20:42 INFO - 2015-11-18 10:20:42,132 DEBUG : BROWSER_OUTPUT: RSS: Main: 146055168
10:20:42 INFO - 2015-11-18 10:20:42,132 DEBUG : BROWSER_OUTPUT:
10:20:43 INFO - 2015-11-18 10:20:43,538 DEBUG : BROWSER_OUTPUT: Cycle 1(3): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:20:44 INFO - 2015-11-18 10:20:44,229 DEBUG : BROWSER_OUTPUT: RSS: Main: 144490496
10:20:44 INFO - 2015-11-18 10:20:44,229 DEBUG : BROWSER_OUTPUT:
10:20:45 INFO - 2015-11-18 10:20:45,626 DEBUG : BROWSER_OUTPUT: Cycle 1(4): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:20:46 INFO - 2015-11-18 10:20:46,396 DEBUG : BROWSER_OUTPUT: RSS: Main: 144896000
10:20:46 INFO - 2015-11-18 10:20:46,396 DEBUG : BROWSER_OUTPUT:
10:20:47 INFO - 2015-11-18 10:20:47,801 DEBUG : BROWSER_OUTPUT: Cycle 1(5): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:20:48 INFO - 2015-11-18 10:20:48,515 DEBUG : BROWSER_OUTPUT: RSS: Main: 141832192
10:20:48 INFO - 2015-11-18 10:20:48,515 DEBUG : BROWSER_OUTPUT:
10:20:49 INFO - 2015-11-18 10:20:49,912 DEBUG : BROWSER_OUTPUT: Cycle 1(6): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:20:50 INFO - 2015-11-18 10:20:50,614 DEBUG : BROWSER_OUTPUT: RSS: Main: 141914112
10:20:50 INFO - 2015-11-18 10:20:50,614 DEBUG : BROWSER_OUTPUT:
10:20:52 INFO - 2015-11-18 10:20:52,241 DEBUG : BROWSER_OUTPUT: Cycle 1(7): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:20:52 INFO - 2015-11-18 10:20:52,947 DEBUG : BROWSER_OUTPUT: RSS: Main: 142258176
10:20:52 INFO - 2015-11-18 10:20:52,948 DEBUG : BROWSER_OUTPUT:
10:20:54 INFO - 2015-11-18 10:20:54,320 DEBUG : BROWSER_OUTPUT: Cycle 1(8): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:20:55 INFO - 2015-11-18 10:20:55,031 DEBUG : BROWSER_OUTPUT: RSS: Main: 142127104
10:20:55 INFO - 2015-11-18 10:20:55,032 DEBUG : BROWSER_OUTPUT:
10:20:56 INFO - 2015-11-18 10:20:56,437 DEBUG : BROWSER_OUTPUT: Cycle 1(9): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:20:57 INFO - 2015-11-18 10:20:57,192 DEBUG : BROWSER_OUTPUT: RSS: Main: 141893632
10:20:57 INFO - 2015-11-18 10:20:57,192 DEBUG : BROWSER_OUTPUT:
10:20:58 INFO - 2015-11-18 10:20:58,602 DEBUG : BROWSER_OUTPUT: Cycle 1(10): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:20:59 INFO - 2015-11-18 10:20:59,304 DEBUG : BROWSER_OUTPUT: RSS: Main: 142069760
10:20:59 INFO - 2015-11-18 10:20:59,304 DEBUG : BROWSER_OUTPUT:
10:21:00 INFO - 2015-11-18 10:21:00,715 DEBUG : BROWSER_OUTPUT: Cycle 1(11): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:21:01 INFO - 2015-11-18 10:21:01,424 DEBUG : BROWSER_OUTPUT: RSS: Main: 142389248
10:21:01 INFO - 2015-11-18 10:21:01,425 DEBUG : BROWSER_OUTPUT:
10:21:02 INFO - 2015-11-18 10:21:02,830 DEBUG : BROWSER_OUTPUT: Cycle 1(12): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:21:03 INFO - 2015-11-18 10:21:03,537 DEBUG : BROWSER_OUTPUT: RSS: Main: 143298560
10:21:03 INFO - 2015-11-18 10:21:03,537 DEBUG : BROWSER_OUTPUT:
10:21:05 INFO - 2015-11-18 10:21:05,143 DEBUG : BROWSER_OUTPUT: Cycle 1(13): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:21:05 INFO - 2015-11-18 10:21:05,853 DEBUG : BROWSER_OUTPUT: RSS: Main: 142671872
10:21:05 INFO - 2015-11-18 10:21:05,854 DEBUG : BROWSER_OUTPUT:
10:21:07 INFO - 2015-11-18 10:21:07,266 DEBUG : BROWSER_OUTPUT: Cycle 1(14): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:21:08 INFO - 2015-11-18 10:21:08,039 DEBUG : BROWSER_OUTPUT: RSS: Main: 142528512
10:21:08 INFO - 2015-11-18 10:21:08,040 DEBUG : BROWSER_OUTPUT:
10:21:09 INFO - 2015-11-18 10:21:09,425 DEBUG : BROWSER_OUTPUT: Cycle 1(15): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:21:10 INFO - 2015-11-18 10:21:10,132 DEBUG : BROWSER_OUTPUT: RSS: Main: 142446592
10:21:10 INFO - 2015-11-18 10:21:10,133 DEBUG : BROWSER_OUTPUT:
10:21:11 INFO - 2015-11-18 10:21:11,731 DEBUG : BROWSER_OUTPUT: Cycle 1(16): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:21:12 INFO - 2015-11-18 10:21:12,440 DEBUG : BROWSER_OUTPUT: RSS: Main: 142184448
10:21:12 INFO - 2015-11-18 10:21:12,441 DEBUG : BROWSER_OUTPUT:
10:21:13 INFO - 2015-11-18 10:21:13,837 DEBUG : BROWSER_OUTPUT: Cycle 1(17): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:21:14 INFO - 2015-11-18 10:21:14,544 DEBUG : BROWSER_OUTPUT: RSS: Main: 141963264
10:21:14 INFO - 2015-11-18 10:21:14,545 DEBUG : BROWSER_OUTPUT:
10:21:15 INFO - 2015-11-18 10:21:15,970 DEBUG : BROWSER_OUTPUT: Cycle 1(18): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:21:16 INFO - 2015-11-18 10:21:16,731 DEBUG : BROWSER_OUTPUT: RSS: Main: 143949824
10:21:16 INFO - 2015-11-18 10:21:16,732 DEBUG : BROWSER_OUTPUT:
10:21:18 INFO - 2015-11-18 10:21:18,145 DEBUG : BROWSER_OUTPUT: Cycle 1(19): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:21:18 INFO - 2015-11-18 10:21:18,848 DEBUG : BROWSER_OUTPUT: RSS: Main: 142241792
10:21:18 INFO - 2015-11-18 10:21:18,848 DEBUG : BROWSER_OUTPUT:
10:21:20 INFO - 2015-11-18 10:21:20,265 DEBUG : BROWSER_OUTPUT: Cycle 1(20): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:21:20 INFO - 2015-11-18 10:21:20,966 DEBUG : BROWSER_OUTPUT: RSS: Main: 142389248
10:21:20 INFO - 2015-11-18 10:21:20,966 DEBUG : BROWSER_OUTPUT:
10:21:22 INFO - 2015-11-18 10:21:22,375 DEBUG : BROWSER_OUTPUT: Cycle 1(21): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:21:23 INFO - 2015-11-18 10:21:23,077 DEBUG : BROWSER_OUTPUT: RSS: Main: 142417920
10:21:23 INFO - 2015-11-18 10:21:23,078 DEBUG : BROWSER_OUTPUT:
10:21:24 INFO - 2015-11-18 10:21:24,697 DEBUG : BROWSER_OUTPUT: Cycle 1(22): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:21:25 INFO - 2015-11-18 10:21:25,403 DEBUG : BROWSER_OUTPUT: RSS: Main: 143220736
10:21:25 INFO - 2015-11-18 10:21:25,403 DEBUG : BROWSER_OUTPUT:
10:21:26 INFO - 2015-11-18 10:21:26,793 DEBUG : BROWSER_OUTPUT: Cycle 1(23): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:21:27 INFO - 2015-11-18 10:21:27,503 DEBUG : BROWSER_OUTPUT: RSS: Main: 150614016
10:21:27 INFO - 2015-11-18 10:21:27,503 DEBUG : BROWSER_OUTPUT:
10:21:27 INFO - 2015-11-18 10:21:27,772 DEBUG : BROWSER_OUTPUT: 1447870887770 addons.productaddons ERROR Request failed certificate checks: [Exception... "SSL is required and URI scheme is not https." nsresult: "0x8000ffff (NS_ERROR_UNEXPECTED)" location: "JS frame :: resource://gre/modules/CertUtils.jsm :: checkCert :: line 145" data: no]
10:21:28 INFO - 2015-11-18 10:21:28,944 DEBUG : BROWSER_OUTPUT: Cycle 1(24): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:21:29 INFO - 2015-11-18 10:21:29,731 DEBUG : BROWSER_OUTPUT: RSS: Main: 156536832
10:21:29 INFO - 2015-11-18 10:21:29,731 DEBUG : BROWSER_OUTPUT:
10:21:31 INFO - 2015-11-18 10:21:31,128 DEBUG : BROWSER_OUTPUT: Cycle 1(25): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html)
10:21:31 INFO - 2015-11-18 10:21:31,836 DEBUG : BROWSER_OUTPUT: RSS: Main: 156450816
10:21:31 INFO - 2015-11-18 10:21:31,836 DEBUG : BROWSER_OUTPUT:
10:21:31 INFO - 2015-11-18 10:21:31,952 DEBUG : BROWSER_OUTPUT:
10:21:31 INFO - 2015-11-18 10:21:31,952 DEBUG : BROWSER_OUTPUT: (firefox:17760): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed
10:21:32 INFO - 2015-11-18 10:21:32,834 DEBUG : BROWSER_OUTPUT: Cycle 1(1): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:21:33 INFO - 2015-11-18 10:21:33,423 DEBUG : BROWSER_OUTPUT: RSS: Main: 150986752
10:21:33 INFO - 2015-11-18 10:21:33,423 DEBUG : BROWSER_OUTPUT:
10:21:34 INFO - 2015-11-18 10:21:34,365 DEBUG : BROWSER_OUTPUT: Cycle 1(2): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:21:34 INFO - 2015-11-18 10:21:34,967 DEBUG : BROWSER_OUTPUT: RSS: Main: 151580672
10:21:34 INFO - 2015-11-18 10:21:34,968 DEBUG : BROWSER_OUTPUT:
10:21:35 INFO - 2015-11-18 10:21:35,889 DEBUG : BROWSER_OUTPUT: Cycle 1(3): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:21:36 INFO - 2015-11-18 10:21:36,496 DEBUG : BROWSER_OUTPUT: RSS: Main: 150511616
10:21:36 INFO - 2015-11-18 10:21:36,496 DEBUG : BROWSER_OUTPUT:
10:21:37 INFO - 2015-11-18 10:21:37,422 DEBUG : BROWSER_OUTPUT: Cycle 1(4): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:21:38 INFO - 2015-11-18 10:21:38,028 DEBUG : BROWSER_OUTPUT: RSS: Main: 142790656
10:21:38 INFO - 2015-11-18 10:21:38,028 DEBUG : BROWSER_OUTPUT:
10:21:38 INFO - 2015-11-18 10:21:38,970 DEBUG : BROWSER_OUTPUT: Cycle 1(5): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:21:39 INFO - 2015-11-18 10:21:39,576 DEBUG : BROWSER_OUTPUT: RSS: Main: 142901248
10:21:39 INFO - 2015-11-18 10:21:39,576 DEBUG : BROWSER_OUTPUT:
10:21:40 INFO - 2015-11-18 10:21:40,498 DEBUG : BROWSER_OUTPUT: Cycle 1(6): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:21:41 INFO - 2015-11-18 10:21:41,102 DEBUG : BROWSER_OUTPUT: RSS: Main: 140406784
10:21:41 INFO - 2015-11-18 10:21:41,103 DEBUG : BROWSER_OUTPUT:
10:21:42 INFO - 2015-11-18 10:21:42,029 DEBUG : BROWSER_OUTPUT: Cycle 1(7): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:21:42 INFO - 2015-11-18 10:21:42,630 DEBUG : BROWSER_OUTPUT: RSS: Main: 140062720
10:21:42 INFO - 2015-11-18 10:21:42,630 DEBUG : BROWSER_OUTPUT:
10:21:43 INFO - 2015-11-18 10:21:43,572 DEBUG : BROWSER_OUTPUT: Cycle 1(8): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:21:44 INFO - 2015-11-18 10:21:44,174 DEBUG : BROWSER_OUTPUT: RSS: Main: 139816960
10:21:44 INFO - 2015-11-18 10:21:44,174 DEBUG : BROWSER_OUTPUT:
10:21:45 INFO - 2015-11-18 10:21:45,101 DEBUG : BROWSER_OUTPUT: Cycle 1(9): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:21:45 INFO - 2015-11-18 10:21:45,714 DEBUG : BROWSER_OUTPUT: RSS: Main: 139984896
10:21:45 INFO - 2015-11-18 10:21:45,714 DEBUG : BROWSER_OUTPUT:
10:21:46 INFO - 2015-11-18 10:21:46,668 DEBUG : BROWSER_OUTPUT: Cycle 1(10): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:21:47 INFO - 2015-11-18 10:21:47,270 DEBUG : BROWSER_OUTPUT: RSS: Main: 140013568
10:21:47 INFO - 2015-11-18 10:21:47,271 DEBUG : BROWSER_OUTPUT:
10:21:48 INFO - 2015-11-18 10:21:48,198 DEBUG : BROWSER_OUTPUT: Cycle 1(11): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:21:48 INFO - 2015-11-18 10:21:48,804 DEBUG : BROWSER_OUTPUT: RSS: Main: 141303808
10:21:48 INFO - 2015-11-18 10:21:48,804 DEBUG : BROWSER_OUTPUT:
10:21:49 INFO - 2015-11-18 10:21:49,718 DEBUG : BROWSER_OUTPUT: Cycle 1(12): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:21:50 INFO - 2015-11-18 10:21:50,312 DEBUG : BROWSER_OUTPUT: RSS: Main: 139898880
10:21:50 INFO - 2015-11-18 10:21:50,312 DEBUG : BROWSER_OUTPUT:
10:21:51 INFO - 2015-11-18 10:21:51,241 DEBUG : BROWSER_OUTPUT: Cycle 1(13): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:21:51 INFO - 2015-11-18 10:21:51,843 DEBUG : BROWSER_OUTPUT: RSS: Main: 140697600
10:21:51 INFO - 2015-11-18 10:21:51,843 DEBUG : BROWSER_OUTPUT:
10:21:52 INFO - 2015-11-18 10:21:52,757 DEBUG : BROWSER_OUTPUT: Cycle 1(14): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:21:53 INFO - 2015-11-18 10:21:53,358 DEBUG : BROWSER_OUTPUT: RSS: Main: 141717504
10:21:53 INFO - 2015-11-18 10:21:53,359 DEBUG : BROWSER_OUTPUT:
10:21:54 INFO - 2015-11-18 10:21:54,293 DEBUG : BROWSER_OUTPUT: Cycle 1(15): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:21:54 INFO - 2015-11-18 10:21:54,899 DEBUG : BROWSER_OUTPUT: RSS: Main: 141750272
10:21:54 INFO - 2015-11-18 10:21:54,899 DEBUG : BROWSER_OUTPUT:
10:21:55 INFO - 2015-11-18 10:21:55,846 DEBUG : BROWSER_OUTPUT: Cycle 1(16): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:21:56 INFO - 2015-11-18 10:21:56,448 DEBUG : BROWSER_OUTPUT: RSS: Main: 141701120
10:21:56 INFO - 2015-11-18 10:21:56,448 DEBUG : BROWSER_OUTPUT:
10:21:57 INFO - 2015-11-18 10:21:57,362 DEBUG : BROWSER_OUTPUT: Cycle 1(17): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:21:57 INFO - 2015-11-18 10:21:57,963 DEBUG : BROWSER_OUTPUT: RSS: Main: 141836288
10:21:57 INFO - 2015-11-18 10:21:57,963 DEBUG : BROWSER_OUTPUT:
10:21:58 INFO - 2015-11-18 10:21:58,898 DEBUG : BROWSER_OUTPUT: Cycle 1(18): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:21:59 INFO - 2015-11-18 10:21:59,500 DEBUG : BROWSER_OUTPUT: RSS: Main: 142807040
10:21:59 INFO - 2015-11-18 10:21:59,500 DEBUG : BROWSER_OUTPUT:
10:22:00 INFO - 2015-11-18 10:22:00,422 DEBUG : BROWSER_OUTPUT: Cycle 1(19): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:22:01 INFO - 2015-11-18 10:22:01,026 DEBUG : BROWSER_OUTPUT: RSS: Main: 140886016
10:22:01 INFO - 2015-11-18 10:22:01,026 DEBUG : BROWSER_OUTPUT:
10:22:01 INFO - 2015-11-18 10:22:01,960 DEBUG : BROWSER_OUTPUT: Cycle 1(20): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:22:02 INFO - 2015-11-18 10:22:02,561 DEBUG : BROWSER_OUTPUT: RSS: Main: 141045760
10:22:02 INFO - 2015-11-18 10:22:02,561 DEBUG : BROWSER_OUTPUT:
10:22:03 INFO - 2015-11-18 10:22:03,496 DEBUG : BROWSER_OUTPUT: Cycle 1(21): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:22:04 INFO - 2015-11-18 10:22:04,107 DEBUG : BROWSER_OUTPUT: RSS: Main: 142585856
10:22:04 INFO - 2015-11-18 10:22:04,107 DEBUG : BROWSER_OUTPUT:
10:22:05 INFO - 2015-11-18 10:22:05,042 DEBUG : BROWSER_OUTPUT: Cycle 1(22): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:22:05 INFO - 2015-11-18 10:22:05,643 DEBUG : BROWSER_OUTPUT: RSS: Main: 141000704
10:22:05 INFO - 2015-11-18 10:22:05,643 DEBUG : BROWSER_OUTPUT:
10:22:06 INFO - 2015-11-18 10:22:06,557 DEBUG : BROWSER_OUTPUT: Cycle 1(23): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:22:07 INFO - 2015-11-18 10:22:07,159 DEBUG : BROWSER_OUTPUT: RSS: Main: 142602240
10:22:07 INFO - 2015-11-18 10:22:07,159 DEBUG : BROWSER_OUTPUT:
10:22:08 INFO - 2015-11-18 10:22:08,081 DEBUG : BROWSER_OUTPUT: Cycle 1(24): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:22:08 INFO - 2015-11-18 10:22:08,674 DEBUG : BROWSER_OUTPUT: RSS: Main: 142385152
10:22:08 INFO - 2015-11-18 10:22:08,675 DEBUG : BROWSER_OUTPUT:
10:22:09 INFO - 2015-11-18 10:22:09,609 DEBUG : BROWSER_OUTPUT: Cycle 1(25): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html)
10:22:09 INFO - 2015-11-18 10:22:09,859 DEBUG : BROWSER_OUTPUT: RSS: Main: 142233600
10:22:09 INFO - 2015-11-18 10:22:09,859 DEBUG : BROWSER_OUTPUT:
10:22:09 INFO - 2015-11-18 10:22:09,860 DEBUG : BROWSER_OUTPUT: __start_tp_report
10:22:09 INFO - 2015-11-18 10:22:09,860 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load
10:22:09 INFO - 2015-11-18 10:22:09,861 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load_details
10:22:09 INFO - 2015-11-18 10:22:09,861 DEBUG : BROWSER_OUTPUT: |i|pagename|runs|
10:22:09 INFO - 2015-11-18 10:22:09,861 DEBUG : BROWSER_OUTPUT: |0;dhtml.html;1272;1314;1327;1352;1338;1337;1538;1330;1339;1329;1339;1342;1544;1332;1326;1543;1328;1345;1338;1332;1332;1541;1338;1367;1334
10:22:09 INFO - 2015-11-18 10:22:09,861 DEBUG : BROWSER_OUTPUT: |1;tablemutation.html;402;397;384;383;389;387;380;382;394;410;394;378;390;379;381;382;380;386;384;381;391;390;381;385;389
10:22:09 INFO - 2015-11-18 10:22:09,861 DEBUG : BROWSER_OUTPUT: __end_tp_report
10:22:09 INFO - 2015-11-18 10:22:09,861 DEBUG : BROWSER_OUTPUT: __start_cc_report
10:22:09 INFO - 2015-11-18 10:22:09,861 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_cycle_collect,2777
10:22:09 INFO - 2015-11-18 10:22:09,862 DEBUG : BROWSER_OUTPUT: __end_cc_report
10:22:09 INFO - 2015-11-18 10:22:09,862 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870929859__endTimestamp
10:22:09 INFO - 2015-11-18 10:22:09,862 DEBUG : BROWSER_OUTPUT:
10:22:09 INFO - 2015-11-18 10:22:09,863 DEBUG : BROWSER_OUTPUT: ------- Summary: start -------
10:22:09 INFO - 2015-11-18 10:22:09,863 DEBUG : BROWSER_OUTPUT: Number of tests: 2
10:22:09 INFO - 2015-11-18 10:22:09,864 DEBUG : BROWSER_OUTPUT:
10:22:09 INFO - 2015-11-18 10:22:09,864 DEBUG : BROWSER_OUTPUT: [#0] dhtml.html Cycles:25 Average:1366.28 Median:1338.00 stddev:79.67 (6.0%) stddev-sans-first:78.87
10:22:09 INFO - 2015-11-18 10:22:09,864 DEBUG : BROWSER_OUTPUT: Values: 1272.0 1314.0 1327.0 1352.0 1338.0 1337.0 1538.0 1330.0 1339.0 1329.0 1339.0 1342.0 1544.0 1332.0 1326.0 1543.0 1328.0 1345.0 1338.0 1332.0 1332.0 1541.0 1338.0 1367.0 1334.0
10:22:09 INFO - 2015-11-18 10:22:09,864 DEBUG : BROWSER_OUTPUT:
10:22:09 INFO - 2015-11-18 10:22:09,864 DEBUG : BROWSER_OUTPUT: [#1] tablemutation.html Cycles:25 Average:387.16 Median:385.00 stddev:7.73 (2.0%) stddev-sans-first:7.24
10:22:09 INFO - 2015-11-18 10:22:09,864 DEBUG : BROWSER_OUTPUT: Values: 402.0 397.0 384.0 383.0 389.0 387.0 380.0 382.0 394.0 410.0 394.0 378.0 390.0 379.0 381.0 382.0 380.0 386.0 384.0 381.0 391.0 390.0 381.0 385.0 389.0
10:22:09 INFO - 2015-11-18 10:22:09,864 DEBUG : BROWSER_OUTPUT: -------- Summary: end --------
10:22:09 INFO - 2015-11-18 10:22:09,864 DEBUG : BROWSER_OUTPUT:
10:22:10 INFO - 2015-11-18 10:22:10,585 INFO : Browser exited with error code: 0
10:22:10 INFO - 2015-11-18 10:22:10,604 INFO : Completed test a11yr (00:01:51)
10:22:10 INFO - 2015-11-18 10:22:10,604 INFO : Starting test ts_paint
10:22:10 INFO - 2015-11-18 10:22:10,604 DEBUG : operating with platform_type : linux_
10:22:10 INFO - 2015-11-18 10:22:10,604 INFO : Initialising browser for ts_paint test...
10:22:10 INFO - 2015-11-18 10:22:10,610 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/getInfo.html
10:22:15 INFO - 2015-11-18 10:22:15,130 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
10:22:15 INFO - 2015-11-18 10:22:15,130 DEBUG : BROWSER_OUTPUT: colorDepth:24
10:22:15 INFO - 2015-11-18 10:22:15,131 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697
10:22:15 INFO - 2015-11-18 10:22:15,131 DEBUG : BROWSER_OUTPUT: __metrics
10:22:16 INFO - 2015-11-18 10:22:16,165 INFO : Browser initialized.
10:22:16 INFO - 2015-11-18 10:22:16,166 INFO : Running cycle 1/20 for ts_paint test...
10:22:16 INFO - 2015-11-18 10:22:16,166 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html
10:22:18 INFO - 2015-11-18 10:22:18,303 DEBUG : BROWSER_OUTPUT: __start_report458__end_report
10:22:18 INFO - 2015-11-18 10:22:18,303 DEBUG : BROWSER_OUTPUT:
10:22:18 INFO - 2015-11-18 10:22:18,311 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870938309__endTimestamp
10:22:19 INFO - 2015-11-18 10:22:19,293 INFO : Browser exited with error code: 0
10:22:19 INFO - 2015-11-18 10:22:19,295 INFO : Running cycle 2/20 for ts_paint test...
10:22:19 INFO - 2015-11-18 10:22:19,295 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html
10:22:20 INFO - 2015-11-18 10:22:20,916 DEBUG : BROWSER_OUTPUT: __start_report512__end_report
10:22:20 INFO - 2015-11-18 10:22:20,917 DEBUG : BROWSER_OUTPUT:
10:22:20 INFO - 2015-11-18 10:22:20,932 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870940924__endTimestamp
10:22:21 INFO - 2015-11-18 10:22:21,857 INFO : Browser exited with error code: 0
10:22:21 INFO - 2015-11-18 10:22:21,859 INFO : Running cycle 3/20 for ts_paint test...
10:22:21 INFO - 2015-11-18 10:22:21,859 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html
10:22:23 INFO - 2015-11-18 10:22:23,513 DEBUG : BROWSER_OUTPUT: __start_report526__end_report
10:22:23 INFO - 2015-11-18 10:22:23,513 DEBUG : BROWSER_OUTPUT:
10:22:23 INFO - 2015-11-18 10:22:23,516 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870943515__endTimestamp
10:22:24 INFO - 2015-11-18 10:22:24,437 INFO : Browser exited with error code: 0
10:22:24 INFO - 2015-11-18 10:22:24,439 INFO : Running cycle 4/20 for ts_paint test...
10:22:24 INFO - 2015-11-18 10:22:24,439 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html
10:22:26 INFO - 2015-11-18 10:22:26,060 DEBUG : BROWSER_OUTPUT: __start_report532__end_report
10:22:26 INFO - 2015-11-18 10:22:26,060 DEBUG : BROWSER_OUTPUT:
10:22:26 INFO - 2015-11-18 10:22:26,067 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870946064__endTimestamp
10:22:27 INFO - 2015-11-18 10:22:27,053 INFO : Browser exited with error code: 0
10:22:27 INFO - 2015-11-18 10:22:27,055 INFO : Running cycle 5/20 for ts_paint test...
10:22:27 INFO - 2015-11-18 10:22:27,055 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html
10:22:28 INFO - 2015-11-18 10:22:28,754 DEBUG : BROWSER_OUTPUT: __start_report602__end_report
10:22:28 INFO - 2015-11-18 10:22:28,754 DEBUG : BROWSER_OUTPUT:
10:22:28 INFO - 2015-11-18 10:22:28,770 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870948765__endTimestamp
10:22:29 INFO - 2015-11-18 10:22:29,777 INFO : Browser exited with error code: 0
10:22:29 INFO - 2015-11-18 10:22:29,779 INFO : Running cycle 6/20 for ts_paint test...
10:22:29 INFO - 2015-11-18 10:22:29,779 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html
10:22:31 INFO - 2015-11-18 10:22:31,395 DEBUG : BROWSER_OUTPUT: __start_report497__end_report
10:22:31 INFO - 2015-11-18 10:22:31,395 DEBUG : BROWSER_OUTPUT:
10:22:31 INFO - 2015-11-18 10:22:31,403 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870951400__endTimestamp
10:22:32 INFO - 2015-11-18 10:22:32,457 INFO : Browser exited with error code: 0
10:22:32 INFO - 2015-11-18 10:22:32,459 INFO : Running cycle 7/20 for ts_paint test...
10:22:32 INFO - 2015-11-18 10:22:32,459 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html
10:22:34 INFO - 2015-11-18 10:22:34,087 DEBUG : BROWSER_OUTPUT: __start_report509__end_report
10:22:34 INFO - 2015-11-18 10:22:34,087 DEBUG : BROWSER_OUTPUT:
10:22:34 INFO - 2015-11-18 10:22:34,103 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870954095__endTimestamp
10:22:35 INFO - 2015-11-18 10:22:35,173 INFO : Browser exited with error code: 0
10:22:35 INFO - 2015-11-18 10:22:35,175 INFO : Running cycle 8/20 for ts_paint test...
10:22:35 INFO - 2015-11-18 10:22:35,175 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html
10:22:36 INFO - 2015-11-18 10:22:36,788 DEBUG : BROWSER_OUTPUT: __start_report502__end_report
10:22:36 INFO - 2015-11-18 10:22:36,788 DEBUG : BROWSER_OUTPUT:
10:22:36 INFO - 2015-11-18 10:22:36,789 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870956788__endTimestamp
10:22:37 INFO - 2015-11-18 10:22:37,821 INFO : Browser exited with error code: 0
10:22:37 INFO - 2015-11-18 10:22:37,823 INFO : Running cycle 9/20 for ts_paint test...
10:22:37 INFO - 2015-11-18 10:22:37,823 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html
10:22:39 INFO - 2015-11-18 10:22:39,477 DEBUG : BROWSER_OUTPUT: __start_report523__end_report
10:22:39 INFO - 2015-11-18 10:22:39,477 DEBUG : BROWSER_OUTPUT:
10:22:39 INFO - 2015-11-18 10:22:39,478 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870959476__endTimestamp
10:22:40 INFO - 2015-11-18 10:22:40,493 INFO : Browser exited with error code: 0
10:22:40 INFO - 2015-11-18 10:22:40,495 INFO : Running cycle 10/20 for ts_paint test...
10:22:40 INFO - 2015-11-18 10:22:40,495 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html
10:22:42 INFO - 2015-11-18 10:22:42,150 DEBUG : BROWSER_OUTPUT: __start_report538__end_report
10:22:42 INFO - 2015-11-18 10:22:42,150 DEBUG : BROWSER_OUTPUT:
10:22:42 INFO - 2015-11-18 10:22:42,158 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870962156__endTimestamp
10:22:43 INFO - 2015-11-18 10:22:43,225 INFO : Browser exited with error code: 0
10:22:43 INFO - 2015-11-18 10:22:43,227 INFO : Running cycle 11/20 for ts_paint test...
10:22:43 INFO - 2015-11-18 10:22:43,227 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html
10:22:44 INFO - 2015-11-18 10:22:44,880 DEBUG : BROWSER_OUTPUT: __start_report552__end_report
10:22:44 INFO - 2015-11-18 10:22:44,881 DEBUG : BROWSER_OUTPUT:
10:22:44 INFO - 2015-11-18 10:22:44,884 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870964883__endTimestamp
10:22:45 INFO - 2015-11-18 10:22:45,953 INFO : Browser exited with error code: 0
10:22:45 INFO - 2015-11-18 10:22:45,955 INFO : Running cycle 12/20 for ts_paint test...
10:22:45 INFO - 2015-11-18 10:22:45,955 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html
10:22:47 INFO - 2015-11-18 10:22:47,636 DEBUG : BROWSER_OUTPUT: __start_report548__end_report
10:22:47 INFO - 2015-11-18 10:22:47,636 DEBUG : BROWSER_OUTPUT:
10:22:47 INFO - 2015-11-18 10:22:47,643 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870967642__endTimestamp
10:22:48 INFO - 2015-11-18 10:22:48,653 INFO : Browser exited with error code: 0
10:22:48 INFO - 2015-11-18 10:22:48,655 INFO : Running cycle 13/20 for ts_paint test...
10:22:48 INFO - 2015-11-18 10:22:48,655 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html
10:22:50 INFO - 2015-11-18 10:22:50,254 DEBUG : BROWSER_OUTPUT: __start_report496__end_report
10:22:50 INFO - 2015-11-18 10:22:50,254 DEBUG : BROWSER_OUTPUT:
10:22:50 INFO - 2015-11-18 10:22:50,257 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870970255__endTimestamp
10:22:51 INFO - 2015-11-18 10:22:51,329 INFO : Browser exited with error code: 0
10:22:51 INFO - 2015-11-18 10:22:51,331 INFO : Running cycle 14/20 for ts_paint test...
10:22:51 INFO - 2015-11-18 10:22:51,331 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html
10:22:52 INFO - 2015-11-18 10:22:52,969 DEBUG : BROWSER_OUTPUT: __start_report486__end_report
10:22:52 INFO - 2015-11-18 10:22:52,970 DEBUG : BROWSER_OUTPUT:
10:22:52 INFO - 2015-11-18 10:22:52,977 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870972975__endTimestamp
10:22:54 INFO - 2015-11-18 10:22:54,089 INFO : Browser exited with error code: 0
10:22:54 INFO - 2015-11-18 10:22:54,091 INFO : Running cycle 15/20 for ts_paint test...
10:22:54 INFO - 2015-11-18 10:22:54,091 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html
10:22:55 INFO - 2015-11-18 10:22:55,747 DEBUG : BROWSER_OUTPUT: __start_report547__end_report
10:22:55 INFO - 2015-11-18 10:22:55,747 DEBUG : BROWSER_OUTPUT:
10:22:55 INFO - 2015-11-18 10:22:55,751 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870975750__endTimestamp
10:22:56 INFO - 2015-11-18 10:22:56,817 INFO : Browser exited with error code: 0
10:22:56 INFO - 2015-11-18 10:22:56,819 INFO : Running cycle 16/20 for ts_paint test...
10:22:56 INFO - 2015-11-18 10:22:56,819 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html
10:22:58 INFO - 2015-11-18 10:22:58,464 DEBUG : BROWSER_OUTPUT: __start_report520__end_report
10:22:58 INFO - 2015-11-18 10:22:58,464 DEBUG : BROWSER_OUTPUT:
10:22:58 INFO - 2015-11-18 10:22:58,472 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870978471__endTimestamp
10:22:59 INFO - 2015-11-18 10:22:59,533 INFO : Browser exited with error code: 0
10:22:59 INFO - 2015-11-18 10:22:59,535 INFO : Running cycle 17/20 for ts_paint test...
10:22:59 INFO - 2015-11-18 10:22:59,535 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html
10:23:01 INFO - 2015-11-18 10:23:01,163 DEBUG : BROWSER_OUTPUT: __start_report510__end_report
10:23:01 INFO - 2015-11-18 10:23:01,163 DEBUG : BROWSER_OUTPUT:
10:23:01 INFO - 2015-11-18 10:23:01,170 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870981166__endTimestamp
10:23:02 INFO - 2015-11-18 10:23:02,373 INFO : Browser exited with error code: 0
10:23:02 INFO - 2015-11-18 10:23:02,375 INFO : Running cycle 18/20 for ts_paint test...
10:23:02 INFO - 2015-11-18 10:23:02,375 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html
10:23:03 INFO - 2015-11-18 10:23:03,991 DEBUG : BROWSER_OUTPUT: __start_report502__end_report
10:23:03 INFO - 2015-11-18 10:23:03,992 DEBUG : BROWSER_OUTPUT:
10:23:03 INFO - 2015-11-18 10:23:03,999 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870983996__endTimestamp
10:23:05 INFO - 2015-11-18 10:23:05,101 INFO : Browser exited with error code: 0
10:23:05 INFO - 2015-11-18 10:23:05,103 INFO : Running cycle 19/20 for ts_paint test...
10:23:05 INFO - 2015-11-18 10:23:05,103 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html
10:23:06 INFO - 2015-11-18 10:23:06,725 DEBUG : BROWSER_OUTPUT: __start_report508__end_report
10:23:06 INFO - 2015-11-18 10:23:06,725 DEBUG : BROWSER_OUTPUT:
10:23:06 INFO - 2015-11-18 10:23:06,741 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870986736__endTimestamp
10:23:07 INFO - 2015-11-18 10:23:07,821 INFO : Browser exited with error code: 0
10:23:07 INFO - 2015-11-18 10:23:07,823 INFO : Running cycle 20/20 for ts_paint test...
10:23:07 INFO - 2015-11-18 10:23:07,823 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html
10:23:09 INFO - 2015-11-18 10:23:09,477 DEBUG : BROWSER_OUTPUT: __start_report546__end_report
10:23:09 INFO - 2015-11-18 10:23:09,477 DEBUG : BROWSER_OUTPUT:
10:23:09 INFO - 2015-11-18 10:23:09,477 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870989474__endTimestamp
10:23:10 INFO - 2015-11-18 10:23:10,525 INFO : Browser exited with error code: 0
10:23:10 INFO - 2015-11-18 10:23:10,544 INFO : Completed test ts_paint (00:00:59)
10:23:10 INFO - 2015-11-18 10:23:10,545 INFO : Starting test tpaint
10:23:10 INFO - 2015-11-18 10:23:10,545 DEBUG : operating with platform_type : linux_
10:23:10 INFO - 2015-11-18 10:23:10,545 INFO : Initialising browser for tpaint test...
10:23:10 INFO - 2015-11-18 10:23:10,551 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmppTGLfv/profile http://localhost:38426/getInfo.html
10:23:15 INFO - 2015-11-18 10:23:15,133 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
10:23:15 INFO - 2015-11-18 10:23:15,133 DEBUG : BROWSER_OUTPUT: colorDepth:24
10:23:15 INFO - 2015-11-18 10:23:15,133 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697
10:23:15 INFO - 2015-11-18 10:23:15,133 DEBUG : BROWSER_OUTPUT: __metrics
10:23:16 INFO - 2015-11-18 10:23:16,269 INFO : Browser initialized.
10:23:16 INFO - 2015-11-18 10:23:16,270 INFO : Running cycle 1/1 for tpaint test...
10:23:16 INFO - 2015-11-18 10:23:16,270 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmppTGLfv/profile file:///builds/slave/test/build/tests/talos/talos/startup_test/tpaint.html?auto=1
10:23:44 INFO - 2015-11-18 10:23:44,822 DEBUG : BROWSER_OUTPUT: __start_report268.65000000000055|275.880000000001|276.630000000001|281.8899999999999|284.71999999999935|287.2049999999999|289.59000000000015|290.89500000000044|295.3249999999998|304.39999999999964|310.77999999999884|320.22500000000036|323.125|335.59000000000015|335.9200000000019|336.1100000000006|350.27999999999884|355.71500000000015|424.6100000000006|463.8250000000007__end_report__startTimestamp1447871024821__endTimestamp
10:23:44 INFO - 2015-11-18 10:23:44,822 DEBUG : BROWSER_OUTPUT: openingTimes=275.880000000001,276.630000000001,281.8899999999999,284.71999999999935,287.2049999999999,289.59000000000015,290.89500000000044,295.3249999999998,304.39999999999964,310.77999999999884,320.22500000000036,323.125,335.59000000000015,335.9200000000019,336.1100000000006,350.27999999999884,355.71500000000015,424.6100000000006,463.8250000000007
10:23:44 INFO - 2015-11-18 10:23:44,822 DEBUG : BROWSER_OUTPUT: avgOpenTime:320.57
10:23:44 INFO - 2015-11-18 10:23:44,822 DEBUG : BROWSER_OUTPUT: minOpenTime:268.65
10:23:44 INFO - 2015-11-18 10:23:44,822 DEBUG : BROWSER_OUTPUT: maxOpenTime:463.83
10:23:44 INFO - 2015-11-18 10:23:44,822 DEBUG : BROWSER_OUTPUT: medOpenTime:307.58999999999924
10:23:44 INFO - 2015-11-18 10:23:44,823 DEBUG : BROWSER_OUTPUT: __xulWinOpenTime:307.58999999999924
10:23:45 INFO - 2015-11-18 10:23:45,961 INFO : Browser exited with error code: 0
10:23:45 INFO - 2015-11-18 10:23:45,978 INFO : Completed test tpaint (00:00:35)
10:23:45 INFO - 2015-11-18 10:23:45,978 INFO : Starting test sessionrestore
10:23:45 INFO - 2015-11-18 10:23:45,978 DEBUG : operating with platform_type : linux_
10:23:45 INFO - 2015-11-18 10:23:45,979 INFO : Initialising browser for sessionrestore test...
10:23:45 INFO - 2015-11-18 10:23:45,989 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_vwIK/profile http://localhost:38426/getInfo.html
10:23:53 INFO - 2015-11-18 10:23:53,694 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
10:23:53 INFO - 2015-11-18 10:23:53,695 DEBUG : BROWSER_OUTPUT: colorDepth:24
10:23:53 INFO - 2015-11-18 10:23:53,695 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1151/811
10:23:53 INFO - 2015-11-18 10:23:53,695 DEBUG : BROWSER_OUTPUT: __metrics
10:23:53 ERROR - 2015-11-18 10:23:53,917 DEBUG : BROWSER_OUTPUT: JavaScript error: chrome://browser/content/browser.js, line 17087: TypeError: browser.permitUnload is not a function
10:23:54 ERROR - 2015-11-18 10:23:54,456 DEBUG : BROWSER_OUTPUT: JavaScript error: chrome://browser/content/browser.js, line 17087: TypeError: browser.permitUnload is not a function
10:23:55 INFO - 2015-11-18 10:23:55,433 INFO : Browser initialized.
10:23:55 INFO - 2015-11-18 10:23:55,434 INFO : Running cycle 1/10 for sessionrestore test...
10:23:55 INFO - 2015-11-18 10:23:55,434 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpH_vwIK/profile/sessionstore.js
10:23:55 INFO - 2015-11-18 10:23:55,437 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpH_vwIK/profile/sessionCheckpoints.json
10:23:55 INFO - 2015-11-18 10:23:55,438 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_vwIK/profile http://localhost:38426/startup_test/sessionrestore/index.html
10:24:01 INFO - 2015-11-18 10:24:01,124 DEBUG : BROWSER_OUTPUT: __start_report1495__end_report
10:24:01 INFO - 2015-11-18 10:24:01,124 DEBUG : BROWSER_OUTPUT:
10:24:01 INFO - 2015-11-18 10:24:01,124 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871041118__endTimestamp
10:24:01 INFO - 2015-11-18 10:24:01,124 DEBUG : BROWSER_OUTPUT:
10:24:01 INFO - 2015-11-18 10:24:01,946 DEBUG : BROWSER_OUTPUT:
10:24:01 INFO - 2015-11-18 10:24:01,948 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
10:24:01 INFO - 2015-11-18 10:24:01,948 DEBUG : BROWSER_OUTPUT:
10:24:01 INFO - 2015-11-18 10:24:01,948 DEBUG : BROWSER_OUTPUT:
10:24:01 INFO - 2015-11-18 10:24:01,948 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
10:24:01 INFO - 2015-11-18 10:24:01,948 DEBUG : BROWSER_OUTPUT:
10:24:01 INFO - 2015-11-18 10:24:01,948 DEBUG : BROWSER_OUTPUT:
10:24:01 INFO - 2015-11-18 10:24:01,948 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
10:24:01 INFO - 2015-11-18 10:24:01,948 DEBUG : BROWSER_OUTPUT:
10:24:02 INFO - 2015-11-18 10:24:02,745 INFO : Browser exited with error code: 0
10:24:02 INFO - 2015-11-18 10:24:02,747 INFO : Running cycle 2/10 for sessionrestore test...
10:24:02 INFO - 2015-11-18 10:24:02,748 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpH_vwIK/profile/sessionstore.js
10:24:02 INFO - 2015-11-18 10:24:02,750 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpH_vwIK/profile/sessionCheckpoints.json
10:24:02 INFO - 2015-11-18 10:24:02,751 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_vwIK/profile http://localhost:38426/startup_test/sessionrestore/index.html
10:24:07 INFO - 2015-11-18 10:24:07,992 DEBUG : BROWSER_OUTPUT: __start_report1207__end_report
10:24:07 INFO - 2015-11-18 10:24:07,992 DEBUG : BROWSER_OUTPUT:
10:24:07 INFO - 2015-11-18 10:24:07,992 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871047986__endTimestamp
10:24:07 INFO - 2015-11-18 10:24:07,992 DEBUG : BROWSER_OUTPUT:
10:24:09 INFO - 2015-11-18 10:24:09,513 INFO : Browser exited with error code: 0
10:24:09 INFO - 2015-11-18 10:24:09,515 INFO : Running cycle 3/10 for sessionrestore test...
10:24:09 INFO - 2015-11-18 10:24:09,515 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpH_vwIK/profile/sessionstore.js
10:24:09 INFO - 2015-11-18 10:24:09,517 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpH_vwIK/profile/sessionCheckpoints.json
10:24:09 INFO - 2015-11-18 10:24:09,518 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_vwIK/profile http://localhost:38426/startup_test/sessionrestore/index.html
10:24:14 INFO - 2015-11-18 10:24:14,595 DEBUG : BROWSER_OUTPUT: __start_report1185__end_report
10:24:14 INFO - 2015-11-18 10:24:14,595 DEBUG : BROWSER_OUTPUT:
10:24:14 INFO - 2015-11-18 10:24:14,595 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871054589__endTimestamp
10:24:14 INFO - 2015-11-18 10:24:14,596 DEBUG : BROWSER_OUTPUT:
10:24:16 INFO - 2015-11-18 10:24:16,197 INFO : Browser exited with error code: 0
10:24:16 INFO - 2015-11-18 10:24:16,199 INFO : Running cycle 4/10 for sessionrestore test...
10:24:16 INFO - 2015-11-18 10:24:16,199 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpH_vwIK/profile/sessionstore.js
10:24:16 INFO - 2015-11-18 10:24:16,201 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpH_vwIK/profile/sessionCheckpoints.json
10:24:16 INFO - 2015-11-18 10:24:16,202 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_vwIK/profile http://localhost:38426/startup_test/sessionrestore/index.html
10:24:21 INFO - 2015-11-18 10:24:21,324 DEBUG : BROWSER_OUTPUT: __start_report1189__end_report
10:24:21 INFO - 2015-11-18 10:24:21,324 DEBUG : BROWSER_OUTPUT:
10:24:21 INFO - 2015-11-18 10:24:21,324 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871061323__endTimestamp
10:24:21 INFO - 2015-11-18 10:24:21,324 DEBUG : BROWSER_OUTPUT:
10:24:22 INFO - 2015-11-18 10:24:22,993 INFO : Browser exited with error code: 0
10:24:22 INFO - 2015-11-18 10:24:22,995 INFO : Running cycle 5/10 for sessionrestore test...
10:24:22 INFO - 2015-11-18 10:24:22,995 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpH_vwIK/profile/sessionstore.js
10:24:22 INFO - 2015-11-18 10:24:22,997 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpH_vwIK/profile/sessionCheckpoints.json
10:24:22 INFO - 2015-11-18 10:24:22,998 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_vwIK/profile http://localhost:38426/startup_test/sessionrestore/index.html
10:24:28 INFO - 2015-11-18 10:24:28,321 DEBUG : BROWSER_OUTPUT: __start_report1188__end_report
10:24:28 INFO - 2015-11-18 10:24:28,321 DEBUG : BROWSER_OUTPUT:
10:24:28 INFO - 2015-11-18 10:24:28,321 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871068315__endTimestamp
10:24:28 INFO - 2015-11-18 10:24:28,321 DEBUG : BROWSER_OUTPUT:
10:24:29 INFO - 2015-11-18 10:24:29,204 DEBUG : BROWSER_OUTPUT: [Child 21241] 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
10:24:29 INFO - 2015-11-18 10:24:29,204 DEBUG : BROWSER_OUTPUT:
10:24:29 INFO - 2015-11-18 10:24:29,205 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
10:24:29 INFO - 2015-11-18 10:24:29,205 DEBUG : BROWSER_OUTPUT:
10:24:29 INFO - 2015-11-18 10:24:29,205 DEBUG : BROWSER_OUTPUT:
10:24:29 INFO - 2015-11-18 10:24:29,205 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
10:24:29 INFO - 2015-11-18 10:24:29,206 DEBUG : BROWSER_OUTPUT:
10:24:30 INFO - 2015-11-18 10:24:30,037 INFO : Browser exited with error code: 0
10:24:30 INFO - 2015-11-18 10:24:30,039 INFO : Running cycle 6/10 for sessionrestore test...
10:24:30 INFO - 2015-11-18 10:24:30,039 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpH_vwIK/profile/sessionstore.js
10:24:30 INFO - 2015-11-18 10:24:30,041 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpH_vwIK/profile/sessionCheckpoints.json
10:24:30 INFO - 2015-11-18 10:24:30,042 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_vwIK/profile http://localhost:38426/startup_test/sessionrestore/index.html
10:24:35 INFO - 2015-11-18 10:24:35,205 DEBUG : BROWSER_OUTPUT: __start_report1185__end_report
10:24:35 INFO - 2015-11-18 10:24:35,205 DEBUG : BROWSER_OUTPUT:
10:24:35 INFO - 2015-11-18 10:24:35,206 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871075205__endTimestamp
10:24:35 INFO - 2015-11-18 10:24:35,206 DEBUG : BROWSER_OUTPUT:
10:24:36 INFO - 2015-11-18 10:24:36,937 INFO : Browser exited with error code: 0
10:24:36 INFO - 2015-11-18 10:24:36,939 INFO : Running cycle 7/10 for sessionrestore test...
10:24:36 INFO - 2015-11-18 10:24:36,939 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpH_vwIK/profile/sessionstore.js
10:24:36 INFO - 2015-11-18 10:24:36,941 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpH_vwIK/profile/sessionCheckpoints.json
10:24:36 INFO - 2015-11-18 10:24:36,942 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_vwIK/profile http://localhost:38426/startup_test/sessionrestore/index.html
10:24:42 INFO - 2015-11-18 10:24:42,129 DEBUG : BROWSER_OUTPUT: __start_report1206__end_report
10:24:42 INFO - 2015-11-18 10:24:42,129 DEBUG : BROWSER_OUTPUT:
10:24:42 INFO - 2015-11-18 10:24:42,129 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871082127__endTimestamp
10:24:42 INFO - 2015-11-18 10:24:42,129 DEBUG : BROWSER_OUTPUT:
10:24:43 INFO - 2015-11-18 10:24:43,007 DEBUG : BROWSER_OUTPUT: [Child 21480] 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
10:24:43 INFO - 2015-11-18 10:24:43,770 INFO : Browser exited with error code: 0
10:24:43 INFO - 2015-11-18 10:24:43,771 INFO : Running cycle 8/10 for sessionrestore test...
10:24:43 INFO - 2015-11-18 10:24:43,772 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpH_vwIK/profile/sessionstore.js
10:24:43 INFO - 2015-11-18 10:24:43,774 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpH_vwIK/profile/sessionCheckpoints.json
10:24:43 INFO - 2015-11-18 10:24:43,774 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_vwIK/profile http://localhost:38426/startup_test/sessionrestore/index.html
10:24:49 INFO - 2015-11-18 10:24:49,083 DEBUG : BROWSER_OUTPUT: __start_report1212__end_report
10:24:49 INFO - 2015-11-18 10:24:49,084 DEBUG : BROWSER_OUTPUT:
10:24:49 INFO - 2015-11-18 10:24:49,084 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871089083__endTimestamp
10:24:49 INFO - 2015-11-18 10:24:49,084 DEBUG : BROWSER_OUTPUT:
10:24:50 INFO - 2015-11-18 10:24:50,825 INFO : Browser exited with error code: 0
10:24:50 INFO - 2015-11-18 10:24:50,827 INFO : Running cycle 9/10 for sessionrestore test...
10:24:50 INFO - 2015-11-18 10:24:50,827 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpH_vwIK/profile/sessionstore.js
10:24:50 INFO - 2015-11-18 10:24:50,829 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpH_vwIK/profile/sessionCheckpoints.json
10:24:50 INFO - 2015-11-18 10:24:50,830 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_vwIK/profile http://localhost:38426/startup_test/sessionrestore/index.html
10:24:55 INFO - 2015-11-18 10:24:55,916 DEBUG : BROWSER_OUTPUT: __start_report1198__end_report
10:24:55 INFO - 2015-11-18 10:24:55,916 DEBUG : BROWSER_OUTPUT:
10:24:55 INFO - 2015-11-18 10:24:55,916 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871095915__endTimestamp
10:24:55 INFO - 2015-11-18 10:24:55,916 DEBUG : BROWSER_OUTPUT:
10:24:57 INFO - 2015-11-18 10:24:57,597 INFO : Browser exited with error code: 0
10:24:57 INFO - 2015-11-18 10:24:57,599 INFO : Running cycle 10/10 for sessionrestore test...
10:24:57 INFO - 2015-11-18 10:24:57,599 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpH_vwIK/profile/sessionstore.js
10:24:57 INFO - 2015-11-18 10:24:57,601 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpH_vwIK/profile/sessionCheckpoints.json
10:24:57 INFO - 2015-11-18 10:24:57,602 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_vwIK/profile http://localhost:38426/startup_test/sessionrestore/index.html
10:25:02 INFO - 2015-11-18 10:25:02,666 DEBUG : BROWSER_OUTPUT: __start_report1167__end_report
10:25:02 INFO - 2015-11-18 10:25:02,666 DEBUG : BROWSER_OUTPUT:
10:25:02 INFO - 2015-11-18 10:25:02,666 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871102664__endTimestamp
10:25:02 INFO - 2015-11-18 10:25:02,666 DEBUG : BROWSER_OUTPUT:
10:25:04 INFO - 2015-11-18 10:25:04,433 INFO : Browser exited with error code: 0
10:25:04 INFO - 2015-11-18 10:25:04,450 INFO : Completed test sessionrestore (00:01:18)
10:25:04 INFO - 2015-11-18 10:25:04,450 INFO : Starting test sessionrestore_no_auto_restore
10:25:04 INFO - 2015-11-18 10:25:04,450 DEBUG : operating with platform_type : linux_
10:25:04 INFO - 2015-11-18 10:25:04,450 INFO : Initialising browser for sessionrestore_no_auto_restore test...
10:25:04 INFO - 2015-11-18 10:25:04,458 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpgOVICc/profile http://localhost:38426/getInfo.html
10:25:08 INFO - 2015-11-18 10:25:08,723 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
10:25:08 INFO - 2015-11-18 10:25:08,723 DEBUG : BROWSER_OUTPUT: colorDepth:24
10:25:08 INFO - 2015-11-18 10:25:08,723 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1151/811
10:25:08 INFO - 2015-11-18 10:25:08,723 DEBUG : BROWSER_OUTPUT: __metrics
10:25:09 INFO - 2015-11-18 10:25:09,761 INFO : Browser initialized.
10:25:09 INFO - 2015-11-18 10:25:09,762 INFO : Running cycle 1/10 for sessionrestore_no_auto_restore test...
10:25:09 INFO - 2015-11-18 10:25:09,762 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpgOVICc/profile/sessionstore.js
10:25:09 INFO - 2015-11-18 10:25:09,764 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpgOVICc/profile/sessionCheckpoints.json
10:25:09 INFO - 2015-11-18 10:25:09,765 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpgOVICc/profile http://localhost:38426/startup_test/sessionrestore/index.html
10:25:11 INFO - 2015-11-18 10:25:11,868 DEBUG : BROWSER_OUTPUT: __start_report1094__end_report
10:25:11 INFO - 2015-11-18 10:25:11,868 DEBUG : BROWSER_OUTPUT:
10:25:11 INFO - 2015-11-18 10:25:11,868 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871111867__endTimestamp
10:25:11 INFO - 2015-11-18 10:25:11,868 DEBUG : BROWSER_OUTPUT:
10:25:12 INFO - 2015-11-18 10:25:12,909 INFO : Browser exited with error code: 0
10:25:12 INFO - 2015-11-18 10:25:12,911 INFO : Running cycle 2/10 for sessionrestore_no_auto_restore test...
10:25:12 INFO - 2015-11-18 10:25:12,911 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpgOVICc/profile/sessionstore.js
10:25:12 INFO - 2015-11-18 10:25:12,913 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpgOVICc/profile/sessionCheckpoints.json
10:25:12 INFO - 2015-11-18 10:25:12,914 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpgOVICc/profile http://localhost:38426/startup_test/sessionrestore/index.html
10:25:14 INFO - 2015-11-18 10:25:14,520 DEBUG : BROWSER_OUTPUT: __start_report780__end_report
10:25:14 INFO - 2015-11-18 10:25:14,520 DEBUG : BROWSER_OUTPUT:
10:25:14 INFO - 2015-11-18 10:25:14,521 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871114519__endTimestamp
10:25:14 INFO - 2015-11-18 10:25:14,521 DEBUG : BROWSER_OUTPUT:
10:25:15 INFO - 2015-11-18 10:25:15,425 INFO : Browser exited with error code: 0
10:25:15 INFO - 2015-11-18 10:25:15,427 INFO : Running cycle 3/10 for sessionrestore_no_auto_restore test...
10:25:15 INFO - 2015-11-18 10:25:15,427 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpgOVICc/profile/sessionstore.js
10:25:15 INFO - 2015-11-18 10:25:15,429 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpgOVICc/profile/sessionCheckpoints.json
10:25:15 INFO - 2015-11-18 10:25:15,430 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpgOVICc/profile http://localhost:38426/startup_test/sessionrestore/index.html
10:25:17 INFO - 2015-11-18 10:25:17,063 DEBUG : BROWSER_OUTPUT: __start_report795__end_report
10:25:17 INFO - 2015-11-18 10:25:17,063 DEBUG : BROWSER_OUTPUT:
10:25:17 INFO - 2015-11-18 10:25:17,063 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871117062__endTimestamp
10:25:17 INFO - 2015-11-18 10:25:17,063 DEBUG : BROWSER_OUTPUT:
10:25:17 INFO - 2015-11-18 10:25:17,949 INFO : Browser exited with error code: 0
10:25:17 INFO - 2015-11-18 10:25:17,951 INFO : Running cycle 4/10 for sessionrestore_no_auto_restore test...
10:25:17 INFO - 2015-11-18 10:25:17,951 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpgOVICc/profile/sessionstore.js
10:25:17 INFO - 2015-11-18 10:25:17,953 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpgOVICc/profile/sessionCheckpoints.json
10:25:17 INFO - 2015-11-18 10:25:17,954 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpgOVICc/profile http://localhost:38426/startup_test/sessionrestore/index.html
10:25:19 INFO - 2015-11-18 10:25:19,594 DEBUG : BROWSER_OUTPUT: __start_report775__end_report
10:25:19 INFO - 2015-11-18 10:25:19,595 DEBUG : BROWSER_OUTPUT:
10:25:19 INFO - 2015-11-18 10:25:19,595 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871119593__endTimestamp
10:25:19 INFO - 2015-11-18 10:25:19,595 DEBUG : BROWSER_OUTPUT:
10:25:20 INFO - 2015-11-18 10:25:20,577 INFO : Browser exited with error code: 0
10:25:20 INFO - 2015-11-18 10:25:20,579 INFO : Running cycle 5/10 for sessionrestore_no_auto_restore test...
10:25:20 INFO - 2015-11-18 10:25:20,579 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpgOVICc/profile/sessionstore.js
10:25:20 INFO - 2015-11-18 10:25:20,581 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpgOVICc/profile/sessionCheckpoints.json
10:25:20 INFO - 2015-11-18 10:25:20,582 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpgOVICc/profile http://localhost:38426/startup_test/sessionrestore/index.html
10:25:22 INFO - 2015-11-18 10:25:22,208 DEBUG : BROWSER_OUTPUT: __start_report771__end_report
10:25:22 INFO - 2015-11-18 10:25:22,208 DEBUG : BROWSER_OUTPUT:
10:25:22 INFO - 2015-11-18 10:25:22,208 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871122206__endTimestamp
10:25:22 INFO - 2015-11-18 10:25:22,208 DEBUG : BROWSER_OUTPUT:
10:25:23 INFO - 2015-11-18 10:25:23,245 INFO : Browser exited with error code: 0
10:25:23 INFO - 2015-11-18 10:25:23,247 INFO : Running cycle 6/10 for sessionrestore_no_auto_restore test...
10:25:23 INFO - 2015-11-18 10:25:23,247 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpgOVICc/profile/sessionstore.js
10:25:23 INFO - 2015-11-18 10:25:23,249 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpgOVICc/profile/sessionCheckpoints.json
10:25:23 INFO - 2015-11-18 10:25:23,250 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpgOVICc/profile http://localhost:38426/startup_test/sessionrestore/index.html
10:25:24 INFO - 2015-11-18 10:25:24,844 DEBUG : BROWSER_OUTPUT: __start_report750__end_report
10:25:24 INFO - 2015-11-18 10:25:24,844 DEBUG : BROWSER_OUTPUT:
10:25:24 INFO - 2015-11-18 10:25:24,844 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871124838__endTimestamp
10:25:24 INFO - 2015-11-18 10:25:24,844 DEBUG : BROWSER_OUTPUT:
10:25:25 INFO - 2015-11-18 10:25:25,901 INFO : Browser exited with error code: 0
10:25:25 INFO - 2015-11-18 10:25:25,903 INFO : Running cycle 7/10 for sessionrestore_no_auto_restore test...
10:25:25 INFO - 2015-11-18 10:25:25,903 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpgOVICc/profile/sessionstore.js
10:25:25 INFO - 2015-11-18 10:25:25,905 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpgOVICc/profile/sessionCheckpoints.json
10:25:25 INFO - 2015-11-18 10:25:25,906 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpgOVICc/profile http://localhost:38426/startup_test/sessionrestore/index.html
10:25:27 INFO - 2015-11-18 10:25:27,477 DEBUG : BROWSER_OUTPUT: __start_report761__end_report
10:25:27 INFO - 2015-11-18 10:25:27,477 DEBUG : BROWSER_OUTPUT:
10:25:27 INFO - 2015-11-18 10:25:27,477 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871127469__endTimestamp
10:25:27 INFO - 2015-11-18 10:25:27,478 DEBUG : BROWSER_OUTPUT:
10:25:28 INFO - 2015-11-18 10:25:28,461 INFO : Browser exited with error code: 0
10:25:28 INFO - 2015-11-18 10:25:28,463 INFO : Running cycle 8/10 for sessionrestore_no_auto_restore test...
10:25:28 INFO - 2015-11-18 10:25:28,463 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpgOVICc/profile/sessionstore.js
10:25:28 INFO - 2015-11-18 10:25:28,465 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpgOVICc/profile/sessionCheckpoints.json
10:25:28 INFO - 2015-11-18 10:25:28,466 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpgOVICc/profile http://localhost:38426/startup_test/sessionrestore/index.html
10:25:30 INFO - 2015-11-18 10:25:30,108 DEBUG : BROWSER_OUTPUT: __start_report778__end_report
10:25:30 INFO - 2015-11-18 10:25:30,109 DEBUG : BROWSER_OUTPUT:
10:25:30 INFO - 2015-11-18 10:25:30,109 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871130108__endTimestamp
10:25:30 INFO - 2015-11-18 10:25:30,109 DEBUG : BROWSER_OUTPUT:
10:25:31 INFO - 2015-11-18 10:25:31,209 INFO : Browser exited with error code: 0
10:25:31 INFO - 2015-11-18 10:25:31,211 INFO : Running cycle 9/10 for sessionrestore_no_auto_restore test...
10:25:31 INFO - 2015-11-18 10:25:31,211 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpgOVICc/profile/sessionstore.js
10:25:31 INFO - 2015-11-18 10:25:31,213 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpgOVICc/profile/sessionCheckpoints.json
10:25:31 INFO - 2015-11-18 10:25:31,214 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpgOVICc/profile http://localhost:38426/startup_test/sessionrestore/index.html
10:25:32 INFO - 2015-11-18 10:25:32,853 DEBUG : BROWSER_OUTPUT: __start_report782__end_report
10:25:32 INFO - 2015-11-18 10:25:32,853 DEBUG : BROWSER_OUTPUT:
10:25:32 INFO - 2015-11-18 10:25:32,853 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871132851__endTimestamp
10:25:32 INFO - 2015-11-18 10:25:32,854 DEBUG : BROWSER_OUTPUT:
10:25:33 INFO - 2015-11-18 10:25:33,889 INFO : Browser exited with error code: 0
10:25:33 INFO - 2015-11-18 10:25:33,891 INFO : Running cycle 10/10 for sessionrestore_no_auto_restore test...
10:25:33 INFO - 2015-11-18 10:25:33,891 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpgOVICc/profile/sessionstore.js
10:25:33 INFO - 2015-11-18 10:25:33,893 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpgOVICc/profile/sessionCheckpoints.json
10:25:33 INFO - 2015-11-18 10:25:33,893 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpgOVICc/profile http://localhost:38426/startup_test/sessionrestore/index.html
10:25:35 INFO - 2015-11-18 10:25:35,480 DEBUG : BROWSER_OUTPUT: __start_report763__end_report
10:25:35 INFO - 2015-11-18 10:25:35,480 DEBUG : BROWSER_OUTPUT:
10:25:35 INFO - 2015-11-18 10:25:35,480 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871135477__endTimestamp
10:25:35 INFO - 2015-11-18 10:25:35,480 DEBUG : BROWSER_OUTPUT:
10:25:36 INFO - 2015-11-18 10:25:36,537 INFO : Browser exited with error code: 0
10:25:36 INFO - 2015-11-18 10:25:36,552 INFO : Completed test sessionrestore_no_auto_restore (00:00:32)
10:25:36 INFO - 2015-11-18 10:25:36,983 INFO : Completed test suite (00:05:17)
10:25:36 INFO - 2015-11-18 10:25:36,983 DEBUG : Working with test: a11yr
10:25:36 INFO - 2015-11-18 10:25:36,984 DEBUG : Generating results file: a11yr
10:25:36 INFO - 2015-11-18 10:25:36,984 DEBUG : Working with test: ts_paint
10:25:36 INFO - 2015-11-18 10:25:36,984 DEBUG : Generating results file: ts_paint
10:25:36 INFO - 2015-11-18 10:25:36,985 DEBUG : Working with test: tpaint
10:25:36 INFO - 2015-11-18 10:25:36,985 DEBUG : Generating results file: tpaint
10:25:36 INFO - 2015-11-18 10:25:36,985 DEBUG : Working with test: sessionrestore
10:25:36 INFO - 2015-11-18 10:25:36,985 DEBUG : Generating results file: sessionrestore
10:25:36 INFO - 2015-11-18 10:25:36,985 DEBUG : Working with test: sessionrestore_no_auto_restore
10:25:36 INFO - 2015-11-18 10:25:36,986 DEBUG : Generating results file: sessionrestore_no_auto_restore
10:25:36 INFO - 2015-11-18 10:25:36,986 INFO : Posting result 0 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
10:25:37 INFO - 2015-11-18 10:25:37,026 DEBUG : process_Request line: a11yr_paint graph.html#tests=[[223,132,43]]
10:25:37 INFO - 2015-11-18 10:25:37,026 DEBUG : process_Request line: a11yr_paint 717.46 graph.html#tests=[[223,132,43]]
10:25:37 INFO - 2015-11-18 10:25:37,026 INFO : Posting result 1 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
10:25:37 INFO - 2015-11-18 10:25:37,084 DEBUG : process_Request line: ts_paint graph.html#tests=[[83,132,43]]
10:25:37 INFO - 2015-11-18 10:25:37,084 DEBUG : process_Request line: ts_paint 519.87 graph.html#tests=[[83,132,43]]
10:25:37 INFO - 2015-11-18 10:25:37,084 INFO : Posting result 2 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
10:25:37 INFO - 2015-11-18 10:25:37,115 DEBUG : process_Request line: tpaint graph.html#tests=[[82,132,43]]
10:25:37 INFO - 2015-11-18 10:25:37,115 DEBUG : process_Request line: tpaint 323.12 graph.html#tests=[[82,132,43]]
10:25:37 INFO - 2015-11-18 10:25:37,115 INFO : Posting result 3 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
10:25:37 INFO - 2015-11-18 10:25:37,236 DEBUG : process_Request line: sessionrestore graph.html#tests=[[313,132,43]]
10:25:37 INFO - 2015-11-18 10:25:37,236 DEBUG : process_Request line: sessionrestore 1220.16 graph.html#tests=[[313,132,43]]
10:25:37 INFO - 2015-11-18 10:25:37,236 INFO : Posting result 4 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
10:25:37 INFO - 2015-11-18 10:25:37,346 DEBUG : process_Request line: sessionrestore_no_auto_restore graph.html#tests=[[315,132,43]]
10:25:37 INFO - 2015-11-18 10:25:37,346 DEBUG : process_Request line: sessionrestore_no_auto_restore 800.02 graph.html#tests=[[315,132,43]]
10:25:37 INFO - 2015-11-18 10:25:37,347 INFO : PERFHERDER_DATA: {"framework": {"name": "talos"}, "suites": [{"lowerIsBetter": true, "subtests": [{"lowerIsBetter": true, "replicates": [1272.0, 1314.0, 1327.0, 1352.0, 1338.0, 1337.0, 1538.0, 1330.0, 1339.0, 1329.0, 1339.0, 1342.0, 1544.0, 1332.0, 1326.0, 1543.0, 1328.0, 1345.0, 1338.0, 1332.0, 1332.0, 1541.0, 1338.0, 1367.0, 1334.0], "unit": "ms", "name": "dhtml.html", "value": 1338.0}, {"lowerIsBetter": true, "replicates": [402.0, 397.0, 384.0, 383.0, 389.0, 387.0, 380.0, 382.0, 394.0, 410.0, 394.0, 378.0, 390.0, 379.0, 381.0, 382.0, 380.0, 386.0, 384.0, 381.0, 391.0, 390.0, 381.0, 385.0, 389.0], "unit": "ms", "name": "tablemutation.html", "value": 384.5}], "name": "a11yr", "value": 717.4598109845805}, {"subtests": [{"replicates": [458.0, 512.0, 526.0, 532.0, 602.0, 497.0, 509.0, 502.0, 523.0, 538.0, 552.0, 548.0, 496.0, 486.0, 547.0, 520.0, 510.0, 502.0, 508.0, 546.0], "name": "ts_paint", "value": 520.0}], "name": "ts_paint", "value": 520.0}, {"subtests": [{"replicates": [268.65000000000055, 275.880000000001, 276.630000000001, 281.8899999999999, 284.71999999999935, 287.2049999999999, 289.59000000000015, 290.89500000000044, 295.3249999999998, 304.39999999999964, 310.77999999999884, 320.22500000000036, 323.125, 335.59000000000015, 335.9200000000019, 336.1100000000006, 350.27999999999884, 355.71500000000015, 424.6100000000006, 463.8250000000007], "name": "tpaint", "value": 323.125}], "name": "tpaint", "value": 323.125}, {"subtests": [{"replicates": [1495.0, 1207.0, 1185.0, 1189.0, 1188.0, 1185.0, 1206.0, 1212.0, 1198.0, 1167.0], "name": "sessionrestore", "value": 1189.0}], "name": "sessionrestore", "value": 1189.0}, {"subtests": [{"replicates": [1094.0, 780.0, 795.0, 775.0, 771.0, 750.0, 761.0, 778.0, 782.0, 763.0], "name": "sessionrestore_no_auto_restore", "value": 775.0}], "name": "sessionrestore_no_auto_restore", "value": 775.0}]}
10:25:37 INFO - RETURN: a11yr_paint: 717.46
10:25:37 INFO - RETURN: ts_paint: 519.87
10:25:37 INFO - RETURN: tpaint: 323.12
10:25:37 INFO - RETURN: sessionrestore: 1220.16
10:25:37 INFO - RETURN: sessionrestore_no_auto_restore: 800.02
10:25:37 INFO - TinderboxPrint: TalosResult: {"graphserver": {"sessionrestore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[313,132,43]]", "result": "1220.16"}, "a11yr_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[223,132,43]]", "result": "717.46"}, "tpaint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[82,132,43]]", "result": "323.12"}, "ts_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[83,132,43]]", "result": "519.87"}, "sessionrestore_no_auto_restore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[315,132,43]]", "result": "800.02"}}}
10:25:37 INFO - Return code: 0
10:25:37 ERROR - # TBPL SUCCESS #
10:25:37 INFO - Running post-action listener: _resource_record_post_action
10:25:37 INFO - Running post-run listener: _resource_record_post_run
10:25:38 INFO - Total resource usage - Wall time: 332s; CPU: 16.0%; Read bytes: 0; Write bytes: 570818560; Read time: 0; Write time: 442308
10:25:38 INFO - install - Wall time: 14s; CPU: 14.0%; Read bytes: 0; Write bytes: 158588928; Read time: 0; Write time: 205824
10:25:38 INFO - run-tests - Wall time: 318s; CPU: 16.0%; Read bytes: 0; Write bytes: 412119040; Read time: 0; Write time: 233796
10:25:38 INFO - Running post-run listener: _upload_blobber_files
10:25:38 INFO - Blob upload gear active.
10:25:38 INFO - There are no files to upload in the directory. Skipping the blob upload mechanism ...
10:25:38 INFO - Copying logs to upload dir...
10:25:38 INFO - mkdir: /builds/slave/test/build/upload/logs
program finished with exit code 0
elapsedTime=359.828126
========= master_lag: 0.02 =========
========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 5 mins, 59 secs) (at 2015-11-18 10:25:37.812088) =========
========= Started set props: build_url (results: 0, elapsed: 0 secs) (at 2015-11-18 10:25:37.815526) =========
bash -c 'for file in `ls -1`; do cat $file; done'
in dir /builds/slave/test/properties (timeout 1200 secs)
watching logfiles {}
argv: ['bash', '-c', 'for file in `ls -1`; do cat $file; done']
environment:
DISPLAY=:0
HOME=/home/cltbld
LANG=en_US.UTF-8
LANGUAGE=en_US:en
LOGNAME=cltbld
MAIL=/var/mail/cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript
NO_EM_RESTART=1
PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
PWD=/builds/slave/test/properties
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
build_url:https://queue.taskcluster.net/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2
program finished with exit code 0
elapsedTime=0.010169
build_url: 'https://queue.taskcluster.net/v1/task/oj_sNZtLRR6uEoCsky80IQ/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-18 10:25:37.866310) =========
========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-11-18 10:25:37.866633) =========
rm -f oauth.txt
in dir /builds/slave/test/. (timeout 1200 secs)
watching logfiles {}
argv: ['rm', '-f', 'oauth.txt']
environment:
DISPLAY=:0
HOME=/home/cltbld
LANG=en_US.UTF-8
LANGUAGE=en_US:en
LOGNAME=cltbld
MAIL=/var/mail/cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript
NO_EM_RESTART=1
PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
PWD=/builds/slave/test
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
program finished with exit code 0
elapsedTime=0.004537
========= master_lag: 0.04 =========
========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-11-18 10:25:37.915872) =========
========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2015-11-18 10:25:37.916201) =========
========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2015-11-18 10:25:37.916501) =========
========= Total master_lag: 0.23 =========