builder: fx-team_yosemite_test-other
slave: t-yosemite-r5-0016
starttime: 1445634055.2
results: success (0)
buildid: 20151023121232
builduid: 70c1a8410c6f4d2891f361e5be11844c
revision: ccb7bb578fb15e0fe344b0e9a3b3628faed8bedc
========= Started set props: master (results: 0, elapsed: 0 secs) (at 2015-10-23 14:00:55.200830) =========
master: http://buildbot-master107.bb.releng.scl3.mozilla.com:8201/
========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2015-10-23 14:00:55.201373) =========
========= Started set props: basedir (results: 0, elapsed: 0 secs) (at 2015-10-23 14:00:55.201725) =========
bash -c pwd
in dir /builds/slave/test/. (timeout 1200 secs)
watching logfiles {}
argv: ['bash', '-c', 'pwd']
environment:
Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.hzmkYpjbIV/Render
GIT_SHARE_BASE_DIR=/builds/git-shared
HG_SHARE_BASE_DIR=/builds/hg-shared
HOME=/Users/cltbld
IDLEIZER_DISABLE_SHUTDOWN=true
LOGNAME=cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NO_EM_RESTART=1
PAGER=/bin/cat
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11
PWD=/builds/slave/test
RUNNER_CONFIG_CMD=/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg
SHELL=/bin/bash
SSH_AUTH_SOCK=/private/tmp/com.apple.launchd.OlDG3iec1b/Listeners
TMPDIR=/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/
TWISTD_LOG_PATH=/builds/slave/twistd.log
USER=cltbld
VERSIONER_PYTHON_PREFER_32_BIT=no
VERSIONER_PYTHON_VERSION=2.7
XPCOM_DEBUG_BREAK=warn
XPC_FLAGS=0x0
XPC_SERVICE_NAME=0
__CF_USER_TEXT_ENCODING=0x1C:0x0:0x0
using PTY: False
/builds/slave/test
program finished with exit code 0
elapsedTime=0.005937
basedir: '/builds/slave/test'
========= Finished set props: basedir (results: 0, elapsed: 0 secs) (at 2015-10-23 14:00:55.290727) =========
========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-10-23 14:00:55.291067) =========
========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-10-23 14:00:55.317847) =========
========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-10-23 14:00:55.318337) =========
rm -rf properties
in dir /builds/slave/test/. (timeout 1200 secs)
watching logfiles {}
argv: ['rm', '-rf', 'properties']
environment:
Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.hzmkYpjbIV/Render
GIT_SHARE_BASE_DIR=/builds/git-shared
HG_SHARE_BASE_DIR=/builds/hg-shared
HOME=/Users/cltbld
IDLEIZER_DISABLE_SHUTDOWN=true
LOGNAME=cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NO_EM_RESTART=1
PAGER=/bin/cat
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11
PWD=/builds/slave/test
RUNNER_CONFIG_CMD=/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg
SHELL=/bin/bash
SSH_AUTH_SOCK=/private/tmp/com.apple.launchd.OlDG3iec1b/Listeners
TMPDIR=/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/
TWISTD_LOG_PATH=/builds/slave/twistd.log
USER=cltbld
VERSIONER_PYTHON_PREFER_32_BIT=no
VERSIONER_PYTHON_VERSION=2.7
XPCOM_DEBUG_BREAK=warn
XPC_FLAGS=0x0
XPC_SERVICE_NAME=0
__CF_USER_TEXT_ENCODING=0x1C:0x0:0x0
using PTY: False
program finished with exit code 0
elapsedTime=0.017623
========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-10-23 14:00:55.367742) =========
========= Started set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-10-23 14:00:55.368103) =========
script_repo_url: https://hg.mozilla.org/build/mozharness
========= Finished set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-10-23 14:00:55.368542) =========
========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-10-23 14:00:55.368858) =========
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:
Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.hzmkYpjbIV/Render
GIT_SHARE_BASE_DIR=/builds/git-shared
HG_SHARE_BASE_DIR=/builds/hg-shared
HOME=/Users/cltbld
IDLEIZER_DISABLE_SHUTDOWN=true
LOGNAME=cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NO_EM_RESTART=1
PAGER=/bin/cat
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11
PWD=/builds/slave/test
RUNNER_CONFIG_CMD=/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg
SHELL=/bin/bash
SSH_AUTH_SOCK=/private/tmp/com.apple.launchd.OlDG3iec1b/Listeners
TMPDIR=/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/
TWISTD_LOG_PATH=/builds/slave/twistd.log
USER=cltbld
VERSIONER_PYTHON_PREFER_32_BIT=no
VERSIONER_PYTHON_VERSION=2.7
XPCOM_DEBUG_BREAK=warn
XPC_FLAGS=0x0
XPC_SERVICE_NAME=0
__CF_USER_TEXT_ENCODING=0x1C:0x0:0x0
using PTY: False
--2015-10-23 14:00:55-- https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py
Resolving hg.mozilla.org... 63.245.215.25, 63.245.215.102
Connecting to hg.mozilla.org|63.245.215.25|:443... connected.
HTTP request sent, awaiting response... 200 Script output follows
Length: 12141 (12K) [text/x-python]
Saving to: `archiver_client.py'
0K .......... . 100% 8.86M=0.001s
2015-10-23 14:00:55 (8.86 MB/s) - `archiver_client.py' saved [12141/12141]
program finished with exit code 0
elapsedTime=0.131940
========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-10-23 14:00:55.516702) =========
========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-10-23 14:00:55.517093) =========
rm -rf scripts
in dir /builds/slave/test/. (timeout 1200 secs)
watching logfiles {}
argv: ['rm', '-rf', 'scripts']
environment:
Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.hzmkYpjbIV/Render
GIT_SHARE_BASE_DIR=/builds/git-shared
HG_SHARE_BASE_DIR=/builds/hg-shared
HOME=/Users/cltbld
IDLEIZER_DISABLE_SHUTDOWN=true
LOGNAME=cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NO_EM_RESTART=1
PAGER=/bin/cat
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11
PWD=/builds/slave/test
RUNNER_CONFIG_CMD=/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg
SHELL=/bin/bash
SSH_AUTH_SOCK=/private/tmp/com.apple.launchd.OlDG3iec1b/Listeners
TMPDIR=/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/
TWISTD_LOG_PATH=/builds/slave/twistd.log
USER=cltbld
VERSIONER_PYTHON_PREFER_32_BIT=no
VERSIONER_PYTHON_VERSION=2.7
XPCOM_DEBUG_BREAK=warn
XPC_FLAGS=0x0
XPC_SERVICE_NAME=0
__CF_USER_TEXT_ENCODING=0x1C:0x0:0x0
using PTY: False
program finished with exit code 0
elapsedTime=0.074919
========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-10-23 14:00:55.607349) =========
========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-10-23 14:00:55.607815) =========
bash -c 'python archiver_client.py mozharness --repo integration/fx-team --rev ccb7bb578fb15e0fe344b0e9a3b3628faed8bedc --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 ccb7bb578fb15e0fe344b0e9a3b3628faed8bedc --destination scripts --debug']
environment:
Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.hzmkYpjbIV/Render
GIT_SHARE_BASE_DIR=/builds/git-shared
HG_SHARE_BASE_DIR=/builds/hg-shared
HOME=/Users/cltbld
IDLEIZER_DISABLE_SHUTDOWN=true
LOGNAME=cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NO_EM_RESTART=1
PAGER=/bin/cat
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11
PWD=/builds/slave/test
RUNNER_CONFIG_CMD=/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg
SHELL=/bin/bash
SSH_AUTH_SOCK=/private/tmp/com.apple.launchd.OlDG3iec1b/Listeners
TMPDIR=/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/
TWISTD_LOG_PATH=/builds/slave/twistd.log
USER=cltbld
VERSIONER_PYTHON_PREFER_32_BIT=no
VERSIONER_PYTHON_VERSION=2.7
XPCOM_DEBUG_BREAK=warn
XPC_FLAGS=0x0
XPC_SERVICE_NAME=0
__CF_USER_TEXT_ENCODING=0x1C:0x0:0x0
using PTY: False
2015-10-23 14:00:55,689 truncating revision to first 12 chars
2015-10-23 14:00:55,689 Setting DEBUG logging.
2015-10-23 14:00:55,689 attempt 1/10
2015-10-23 14:00:55,689 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/integration/fx-team/ccb7bb578fb1?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness
2015-10-23 14:00:56,275 unpacking tar archive at: fx-team-ccb7bb578fb1/testing/mozharness/
program finished with exit code 0
elapsedTime=0.839635
========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-10-23 14:00:56.464279) =========
========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-10-23 14:00:56.464676) =========
========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-10-23 14:00:56.477421) =========
========= Started tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-10-23 14:00:56.477793) =========
TinderboxPrint: script_revlink: https://hg.mozilla.org/build/mozharness/rev/production
========= Finished tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-10-23 14:00:56.478268) =========
========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 6 mins, 49 secs) (at 2015-10-23 14:00:56.478599) =========
/tools/buildbot/bin/python scripts/scripts/talos_script.py --suite other --add-option --webServer,localhost --branch-name Fx-Team --system-bits 64 --cfg talos/mac_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Fx-Team
in dir /builds/slave/test/. (timeout 3600 secs) (maxTime 7200 secs)
watching logfiles {}
argv: ['/tools/buildbot/bin/python', 'scripts/scripts/talos_script.py', '--suite', 'other', '--add-option', '--webServer,localhost', '--branch-name', 'Fx-Team', '--system-bits', '64', '--cfg', 'talos/mac_config.py', '--download-symbols', 'ondemand', '--use-talos-json', '--blob-upload-branch', 'Fx-Team']
environment:
Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.hzmkYpjbIV/Render
GIT_SHARE_BASE_DIR=/builds/git-shared
HG_SHARE_BASE_DIR=/builds/hg-shared
HOME=/Users/cltbld
IDLEIZER_DISABLE_SHUTDOWN=true
LOGNAME=cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NO_EM_RESTART=1
PAGER=/bin/cat
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11
PROPERTIES_FILE=/builds/slave/test/buildprops.json
PWD=/builds/slave/test
RUNNER_CONFIG_CMD=/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg
SHELL=/bin/bash
SSH_AUTH_SOCK=/private/tmp/com.apple.launchd.OlDG3iec1b/Listeners
TMPDIR=/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/
TWISTD_LOG_PATH=/builds/slave/twistd.log
USER=cltbld
VERSIONER_PYTHON_PREFER_32_BIT=no
VERSIONER_PYTHON_VERSION=2.7
XPCOM_DEBUG_BREAK=warn
XPC_FLAGS=0x0
XPC_SERVICE_NAME=0
__CF_USER_TEXT_ENCODING=0x1C:0x0:0x0
using PTY: False
14:00:56 INFO - MultiFileLogger online at 20151023 14:00:56 in /builds/slave/test
14:00:56 INFO - Run as scripts/scripts/talos_script.py --suite other --add-option --webServer,localhost --branch-name Fx-Team --system-bits 64 --cfg talos/mac_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Fx-Team
14:00:56 INFO - Dumping config to /builds/slave/test/logs/localconfig.json.
14:00:56 INFO - {'append_to_log': False,
14:00:56 INFO - 'base_work_dir': '/builds/slave/test',
14:00:56 INFO - 'blob_upload_branch': 'Fx-Team',
14:00:56 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt',
14:00:56 INFO - 'branch': 'Fx-Team',
14:00:56 INFO - 'buildbot_json_path': 'buildprops.json',
14:00:56 INFO - 'config_files': ('talos/mac_config.py',),
14:00:56 INFO - 'default_actions': ('clobber',
14:00:56 INFO - 'read-buildbot-config',
14:00:56 INFO - 'download-and-extract',
14:00:56 INFO - 'populate-webroot',
14:00:56 INFO - 'create-virtualenv',
14:00:56 INFO - 'install',
14:00:56 INFO - 'run-tests'),
14:00:56 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',),
14:00:56 INFO - 'download_minidump_stackwalk': True,
14:00:56 INFO - 'download_symbols': 'ondemand',
14:00:56 INFO - 'exes': {'python': '/tools/buildbot/bin/python',
14:00:56 INFO - 'tooltool.py': '/tools/tooltool.py',
14:00:56 INFO - 'virtualenv': ('/tools/buildbot/bin/python',
14:00:56 INFO - '/tools/misc-python/virtualenv.py')},
14:00:56 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub',
14:00:56 INFO - 'http://pypi.pub.build.mozilla.org/pub'),
14:00:56 INFO - 'installer_path': 'installer.exe',
14:00:56 INFO - 'log_level': 'info',
14:00:56 INFO - 'log_name': 'talos',
14:00:56 INFO - 'log_to_console': True,
14:00:56 INFO - 'minidump_stackwalk_path': 'macosx64-minidump_stackwalk',
14:00:56 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/macosx64/releng.manifest',
14:00:56 INFO - 'opt_config_files': (),
14:00:56 INFO - 'pip_index': False,
14:00:56 INFO - 'postflight_run_cmd_suites': ({'architectures': ('32bit', '64bit'),
14:00:56 INFO - 'cmd': ('bash',
14:00:56 INFO - '-c',
14:00:56 INFO - 'screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'),
14:00:56 INFO - 'enabled': True,
14:00:56 INFO - 'halt_on_failure': False,
14:00:56 INFO - 'name': 'check_screen_resolution'},),
14:00:56 INFO - 'preflight_run_cmd_suites': ({'architectures': ('32bit', '64bit'),
14:00:56 INFO - 'cmd': ('bash',
14:00:56 INFO - '-c',
14:00:56 INFO - 'screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'),
14:00:56 INFO - 'enabled': True,
14:00:56 INFO - 'halt_on_failure': False,
14:00:56 INFO - 'name': 'check_screen_resolution'},),
14:00:56 INFO - 'run_cmd_checks_enabled': True,
14:00:56 INFO - 'sps_profile': False,
14:00:56 INFO - 'sps_profile_interval': 0,
14:00:56 INFO - 'suite': 'other',
14:00:56 INFO - 'system_bits': '64',
14:00:56 INFO - 'talos_extra_options': ('--webServer', 'localhost'),
14:00:56 INFO - 'title': 't-yosemite-r5-0016',
14:00:56 INFO - 'tooltool_cache': '/builds/tooltool_cache',
14:00:56 INFO - 'use_talos_json': True,
14:00:56 INFO - 'virtualenv_path': '/builds/slave/test/build/venv',
14:00:56 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None},
14:00:56 INFO - 'work_dir': 'build'}
14:00:56 INFO - #####
14:00:56 INFO - ##### Running clobber step.
14:00:56 INFO - #####
14:00:56 INFO - Running pre-action listener: _resource_record_pre_action
14:00:56 INFO - Running main action method: clobber
14:00:56 INFO - rmtree: /builds/slave/test/build
14:00:56 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1
14:01:00 INFO - Running post-action listener: _resource_record_post_action
14:01:00 INFO - #####
14:01:00 INFO - ##### Running read-buildbot-config step.
14:01:00 INFO - #####
14:01:00 INFO - Running pre-action listener: _resource_record_pre_action
14:01:00 INFO - Running main action method: read_buildbot_config
14:01:00 INFO - Using buildbot properties:
14:01:00 INFO - {
14:01:00 INFO - "properties": {
14:01:00 INFO - "buildnumber": 205,
14:01:00 INFO - "product": "firefox",
14:01:00 INFO - "script_repo_revision": "production",
14:01:00 INFO - "builddir": "fx-team_yosemite_test-other",
14:01:00 INFO - "repository": "",
14:01:00 INFO - "buildername": "Rev5 MacOSX Yosemite 10.10 fx-team talos other",
14:01:00 INFO - "buildid": "20151023121232",
14:01:00 INFO - "slavename": "t-yosemite-r5-0016",
14:01:00 INFO - "pgo_build": "False",
14:01:00 INFO - "basedir": "/builds/slave/test",
14:01:00 INFO - "project": "",
14:01:00 INFO - "platform": "yosemite",
14:01:00 INFO - "master": "http://buildbot-master107.bb.releng.scl3.mozilla.com:8201/",
14:01:00 INFO - "slavebuilddir": "test",
14:01:00 INFO - "scheduler": "tests-fx-team-macosx64-talos",
14:01:00 INFO - "branch": "fx-team",
14:01:00 INFO - "repo_path": "integration/fx-team",
14:01:00 INFO - "stage_platform": "macosx64",
14:01:00 INFO - "builduid": "70c1a8410c6f4d2891f361e5be11844c",
14:01:00 INFO - "revision": "ccb7bb578fb15e0fe344b0e9a3b3628faed8bedc"
14:01:00 INFO - },
14:01:00 INFO - "sourcestamp": {
14:01:00 INFO - "repository": "",
14:01:00 INFO - "hasPatch": false,
14:01:00 INFO - "project": "",
14:01:00 INFO - "branch": "fx-team-macosx64-talos",
14:01:00 INFO - "changes": [
14:01:00 INFO - {
14:01:00 INFO - "category": null,
14:01:00 INFO - "files": [
14:01:00 INFO - {
14:01:00 INFO - "url": null,
14:01:00 INFO - "name": "https://queue.taskcluster.net/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.dmg"
14:01:00 INFO - }
14:01:00 INFO - ],
14:01:00 INFO - "repository": "",
14:01:00 INFO - "rev": "ccb7bb578fb15e0fe344b0e9a3b3628faed8bedc",
14:01:00 INFO - "who": "dtownsend@mozilla.com",
14:01:00 INFO - "when": 1445633444,
14:01:00 INFO - "number": 6567866,
14:01:00 INFO - "comments": "Bug 1217070: Fix accessing the bootstrap methods when they are declared in the new lexical scope. r=rhelmer\n\nRather that trying to get the method from the sandbox global object which will\nonly work for var and function declared methods instead evaluate the function\nname in the sandbox scope and get the result which will give us access to the\nlexical scope.",
14:01:00 INFO - "project": "",
14:01:00 INFO - "at": "Fri 23 Oct 2015 13:50:44",
14:01:00 INFO - "branch": "fx-team-macosx64-talos",
14:01:00 INFO - "revlink": "",
14:01:00 INFO - "properties": [
14:01:00 INFO - [
14:01:00 INFO - "buildid",
14:01:00 INFO - "20151023121232",
14:01:00 INFO - "Change"
14:01:00 INFO - ],
14:01:00 INFO - [
14:01:00 INFO - "builduid",
14:01:00 INFO - "70c1a8410c6f4d2891f361e5be11844c",
14:01:00 INFO - "Change"
14:01:00 INFO - ],
14:01:00 INFO - [
14:01:00 INFO - "pgo_build",
14:01:00 INFO - "False",
14:01:00 INFO - "Change"
14:01:00 INFO - ]
14:01:00 INFO - ],
14:01:00 INFO - "revision": "ccb7bb578fb15e0fe344b0e9a3b3628faed8bedc"
14:01:00 INFO - }
14:01:00 INFO - ],
14:01:00 INFO - "revision": "ccb7bb578fb15e0fe344b0e9a3b3628faed8bedc"
14:01:00 INFO - }
14:01:00 INFO - }
14:01:00 INFO - Found installer url https://queue.taskcluster.net/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.dmg.
14:01:00 INFO - Running post-action listener: _resource_record_post_action
14:01:00 INFO - #####
14:01:00 INFO - ##### Running download-and-extract step.
14:01:00 INFO - #####
14:01:00 INFO - Running pre-action listener: _resource_record_pre_action
14:01:00 INFO - Running main action method: download_and_extract
14:01:00 INFO - mkdir: /builds/slave/test/build/tests
14:01: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')]}
14:01:00 INFO - https://queue.taskcluster.net/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/test_packages.json matches https://queue.taskcluster.net
14:01:00 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/test_packages.json
14:01:00 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/test_packages.json
14:01:00 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/test_packages.json to /builds/slave/test/build/test_packages.json
14:01:00 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/test_packages.json', 'file_name': '/builds/slave/test/build/test_packages.json'}, attempt #1
14:01:00 INFO - Downloaded 1149 bytes.
14:01:00 INFO - Reading from file /builds/slave/test/build/test_packages.json
14:01:00 INFO - Using the following test package requirements:
14:01:00 INFO - {u'common': [u'firefox-44.0a1.en-US.mac.common.tests.zip'],
14:01:00 INFO - u'cppunittest': [u'firefox-44.0a1.en-US.mac.common.tests.zip',
14:01:00 INFO - u'firefox-44.0a1.en-US.mac.cppunittest.tests.zip'],
14:01:00 INFO - u'jittest': [u'firefox-44.0a1.en-US.mac.common.tests.zip',
14:01:00 INFO - u'jsshell-mac.zip'],
14:01:00 INFO - u'mochitest': [u'firefox-44.0a1.en-US.mac.common.tests.zip',
14:01:00 INFO - u'firefox-44.0a1.en-US.mac.mochitest.tests.zip'],
14:01:00 INFO - u'mozbase': [u'firefox-44.0a1.en-US.mac.common.tests.zip'],
14:01:00 INFO - u'reftest': [u'firefox-44.0a1.en-US.mac.common.tests.zip',
14:01:00 INFO - u'firefox-44.0a1.en-US.mac.reftest.tests.zip'],
14:01:00 INFO - u'talos': [u'firefox-44.0a1.en-US.mac.common.tests.zip',
14:01:00 INFO - u'firefox-44.0a1.en-US.mac.talos.tests.zip'],
14:01:00 INFO - u'web-platform': [u'firefox-44.0a1.en-US.mac.common.tests.zip',
14:01:00 INFO - u'firefox-44.0a1.en-US.mac.web-platform.tests.zip'],
14:01:00 INFO - u'webapprt': [u'firefox-44.0a1.en-US.mac.common.tests.zip'],
14:01:00 INFO - u'xpcshell': [u'firefox-44.0a1.en-US.mac.common.tests.zip',
14:01:00 INFO - u'firefox-44.0a1.en-US.mac.xpcshell.tests.zip']}
14:01:00 INFO - Downloading packages: [u'firefox-44.0a1.en-US.mac.common.tests.zip'] for test suite category: common
14:01: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')]}
14:01:00 INFO - https://queue.taskcluster.net/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.common.tests.zip matches https://queue.taskcluster.net
14:01:00 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.common.tests.zip
14:01:00 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.common.tests.zip
14:01:00 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.common.tests.zip to /builds/slave/test/build/firefox-44.0a1.en-US.mac.common.tests.zip
14:01:00 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.common.tests.zip', 'file_name': u'/builds/slave/test/build/firefox-44.0a1.en-US.mac.common.tests.zip'}, attempt #1
14:01:01 INFO - Downloaded 17447745 bytes.
14:01:01 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-44.0a1.en-US.mac.common.tests.zip'] in /builds/slave/test/build/tests
14:01:01 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-44.0a1.en-US.mac.common.tests.zip
14:01:01 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-44.0a1.en-US.mac.common.tests.zip'] with output_timeout 1760
14:01:06 INFO - Return code: 0
14:01:06 INFO - Downloading packages: [u'firefox-44.0a1.en-US.mac.common.tests.zip', u'firefox-44.0a1.en-US.mac.talos.tests.zip'] for test suite category: talos
14:01:06 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
14:01:06 INFO - https://queue.taskcluster.net/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.common.tests.zip matches https://queue.taskcluster.net
14:01:06 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.common.tests.zip
14:01:06 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.common.tests.zip
14:01:06 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.common.tests.zip to /builds/slave/test/build/firefox-44.0a1.en-US.mac.common.tests.zip
14:01:06 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.common.tests.zip', 'file_name': u'/builds/slave/test/build/firefox-44.0a1.en-US.mac.common.tests.zip'}, attempt #1
14:01:09 INFO - Downloaded 17447745 bytes.
14:01:09 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-44.0a1.en-US.mac.common.tests.zip'] in /builds/slave/test/build/tests
14:01:09 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-44.0a1.en-US.mac.common.tests.zip
14:01:09 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-44.0a1.en-US.mac.common.tests.zip'] with output_timeout 1760
14:01:13 INFO - Return code: 0
14:01:13 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')]}
14:01:13 INFO - https://queue.taskcluster.net/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.talos.tests.zip matches https://queue.taskcluster.net
14:01:13 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.talos.tests.zip
14:01:13 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.talos.tests.zip
14:01:13 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.talos.tests.zip to /builds/slave/test/build/firefox-44.0a1.en-US.mac.talos.tests.zip
14:01:13 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.talos.tests.zip', 'file_name': u'/builds/slave/test/build/firefox-44.0a1.en-US.mac.talos.tests.zip'}, attempt #1
14:01:17 INFO - Downloaded 11131307 bytes.
14:01:17 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-44.0a1.en-US.mac.talos.tests.zip'] in /builds/slave/test/build/tests
14:01:17 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-44.0a1.en-US.mac.talos.tests.zip
14:01:17 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-44.0a1.en-US.mac.talos.tests.zip'] with output_timeout 1760
14:01:18 INFO - Return code: 0
14:01:18 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')]}
14:01:18 INFO - https://queue.taskcluster.net/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.dmg matches https://queue.taskcluster.net
14:01:18 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.dmg
14:01:18 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.dmg
14:01:18 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.dmg to /builds/slave/test/build/firefox-44.0a1.en-US.mac.dmg
14:01:18 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.dmg', 'file_name': '/builds/slave/test/build/firefox-44.0a1.en-US.mac.dmg'}, attempt #1
14:01:21 INFO - Downloaded 108352699 bytes.
14:01:21 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.dmg
14:01:21 INFO - mkdir: /builds/slave/test/properties
14:01:21 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url
14:01:21 INFO - Writing to file /builds/slave/test/properties/build_url
14:01:21 INFO - Contents:
14:01:21 INFO - build_url:https://queue.taskcluster.net/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.dmg
14:01:21 INFO - Running post-action listener: _resource_record_post_action
14:01:21 INFO - Running post-action listener: set_extra_try_arguments
14:01:21 INFO - #####
14:01:21 INFO - ##### Running populate-webroot step.
14:01:21 INFO - #####
14:01:21 INFO - Running pre-action listener: _resource_record_pre_action
14:01:21 INFO - Running main action method: populate_webroot
14:01:21 INFO - Guessing talos json url...
14:01:21 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')]}
14:01:21 INFO - https://queue.taskcluster.net/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.txt matches https://queue.taskcluster.net
14:01:21 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.txt
14:01:21 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.txt
14:01:21 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.txt to /builds/slave/test/build/firefox-44.0a1.en-US.mac.txt
14:01:21 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.txt', 'file_name': '/builds/slave/test/build/firefox-44.0a1.en-US.mac.txt'}, attempt #1
14:01:21 INFO - Downloaded 103 bytes.
14:01:21 INFO - Reading from file /builds/slave/test/build/firefox-44.0a1.en-US.mac.txt
14:01:21 INFO - Contents:
14:01:21 INFO - 20151023121232
14:01:21 INFO - https://hg.mozilla.org/integration/fx-team/rev/ccb7bb578fb15e0fe344b0e9a3b3628faed8bedc
14:01:21 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')]}
14:01:21 INFO - trying https://hg.mozilla.org/integration/fx-team/raw-file/ccb7bb578f/testing/talos/talos.json
14:01:21 INFO - Downloading https://hg.mozilla.org/integration/fx-team/raw-file/ccb7bb578f/testing/talos/talos.json to /builds/slave/test/build/talos.json
14:01:21 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://hg.mozilla.org/integration/fx-team/raw-file/ccb7bb578f/testing/talos/talos.json', 'file_name': '/builds/slave/test/build/talos.json'}, attempt #1
14:01:22 INFO - Downloaded 4264 bytes.
14:01:22 INFO - {'extra_options': {'android': ['--apkPath=%(apk_path)s']},
14:01:22 INFO - 'mobile-suites': {'remote-tp4m_nochrome': {'tests': ['tp4m']},
14:01:22 INFO - 'remote-trobocheck2': {'talos_options': ['--fennecIDs',
14:01:22 INFO - '../fennec_ids.txt'],
14:01:22 INFO - 'tests': ['tcheck2']},
14:01:22 INFO - 'remote-tsvgx': {'talos_options': ['--noChrome',
14:01:22 INFO - '--tppagecycles',
14:01:22 INFO - '7'],
14:01:22 INFO - 'tests': ['tsvgm']}},
14:01:22 INFO - 'suites': {'chromez': {'tests': ['tresize', 'tcanvasmark']},
14:01:22 INFO - 'chromez-e10s': {'talos_options': ['--e10s'],
14:01:22 INFO - 'tests': ['tresize', 'tcanvasmark']},
14:01:22 INFO - 'dromaeojs': {'tests': ['dromaeo_css', 'kraken', 'v8_7']},
14:01:22 INFO - 'dromaeojs-e10s': {'talos_options': ['--e10s'],
14:01:22 INFO - 'tests': ['dromaeo_css', 'kraken', 'v8_7']},
14:01:22 INFO - 'g1': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
14:01:22 INFO - 'tests': ['tp5o_scroll', 'glterrain']},
14:01:22 INFO - 'g1-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
14:01:22 INFO - 'talos_options': ['--e10s'],
14:01:22 INFO - 'tests': ['tp5o_scroll', 'glterrain']},
14:01:22 INFO - 'g2': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
14:01:22 INFO - 'tests': ['damp', 'tps']},
14:01:22 INFO - 'g2-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
14:01:22 INFO - 'talos_options': ['--e10s'],
14:01:22 INFO - 'tests': ['damp', 'tps']},
14:01:22 INFO - 'g3': {'tests': ['dromaeo_dom']},
14:01:22 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']},
14:01:22 INFO - 'other': {'tests': ['a11yr',
14:01:22 INFO - 'ts_paint',
14:01:22 INFO - 'tpaint',
14:01:22 INFO - 'sessionrestore',
14:01:22 INFO - 'sessionrestore_no_auto_restore']},
14:01:22 INFO - 'other-e10s': {'talos_options': ['--e10s'],
14:01:22 INFO - 'tests': ['a11yr',
14:01:22 INFO - 'ts_paint',
14:01:22 INFO - 'tpaint',
14:01:22 INFO - 'sessionrestore',
14:01:22 INFO - 'sessionrestore_no_auto_restore']},
14:01:22 INFO - 'other-e10s_l64': {'talos_options': ['--e10s'],
14:01:22 INFO - 'tests': ['a11yr',
14:01:22 INFO - 'ts_paint',
14:01:22 INFO - 'tpaint',
14:01:22 INFO - 'sessionrestore',
14:01:22 INFO - 'sessionrestore_no_auto_restore']},
14:01:22 INFO - 'other-e10s_nol64': {'talos_options': ['--e10s'],
14:01:22 INFO - 'tests': ['a11yr',
14:01:22 INFO - 'ts_paint',
14:01:22 INFO - 'tpaint',
14:01:22 INFO - 'sessionrestore',
14:01:22 INFO - 'sessionrestore_no_auto_restore']},
14:01:22 INFO - 'other_l64': {'tests': ['a11yr',
14:01:22 INFO - 'ts_paint',
14:01:22 INFO - 'tpaint',
14:01:22 INFO - 'sessionrestore',
14:01:22 INFO - 'sessionrestore_no_auto_restore']},
14:01:22 INFO - 'other_nol64': {'tests': ['a11yr',
14:01:22 INFO - 'ts_paint',
14:01:22 INFO - 'tpaint',
14:01:22 INFO - 'sessionrestore',
14:01:22 INFO - 'sessionrestore_no_auto_restore']},
14:01:22 INFO - 'svgr': {'tests': ['tsvgx',
14:01:22 INFO - 'tsvgr_opacity',
14:01:22 INFO - 'tart',
14:01:22 INFO - 'tscrollx',
14:01:22 INFO - 'cart']},
14:01:22 INFO - 'svgr-e10s': {'talos_options': ['--e10s'],
14:01:22 INFO - 'tests': ['tsvgx',
14:01:22 INFO - 'tsvgr_opacity',
14:01:22 INFO - 'tart',
14:01:22 INFO - 'tscrollx',
14:01:22 INFO - 'cart']},
14:01:22 INFO - 'tp5o': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
14:01:22 INFO - 'tests': ['tp5o']},
14:01:22 INFO - 'tp5o-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
14:01:22 INFO - 'talos_options': ['--e10s'],
14:01:22 INFO - 'tests': ['tp5o']},
14:01:22 INFO - 'xperf': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
14:01:22 INFO - 'talos_options': ['--xperf_path',
14:01:22 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'],
14:01:22 INFO - 'tests': ['tp5n']},
14:01:22 INFO - 'xperf-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip',
14:01:22 INFO - 'talos_options': ['--e10s',
14:01:22 INFO - '--xperf_path',
14:01:22 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"',
14:01:22 INFO - 'C:/slave/talos-data/talos/xperf.config'],
14:01:22 INFO - 'tests': ['tp5n']}},
14:01:22 INFO - 'talos.zip': {'path': '',
14:01:22 INFO - 'url': 'http://talos-bundles.pvt.build.mozilla.org/zips/talos.a6052c33d420.zip'}}
14:01:22 INFO - Running post-action listener: _resource_record_post_action
14:01:22 INFO - #####
14:01:22 INFO - ##### Running create-virtualenv step.
14:01:22 INFO - #####
14:01:22 INFO - Running pre-action listener: _resource_record_pre_action
14:01:22 INFO - Running main action method: create_virtualenv
14:01:22 INFO - Creating virtualenv /builds/slave/test/build/venv
14:01:22 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
14:01:22 INFO - Copy/paste: /tools/buildbot/bin/python /tools/misc-python/virtualenv.py --no-site-packages --distribute /builds/slave/test/build/venv
14:01:22 INFO - The --no-site-packages flag is deprecated; it is now the default behavior.
14:01:22 INFO - Using real prefix '/tools/python27'
14:01:22 INFO - New python executable in /builds/slave/test/build/venv/bin/python
14:01:23 INFO - Installing distribute.............................................................................................................................................................................................done.
14:01:26 INFO - Installing pip.................done.
14:01:26 INFO - Return code: 0
14:01:26 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv
14:01:26 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
14:01:26 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
14:01:26 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
14:01:26 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
14:01:26 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
14:01:26 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
14:01:26 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 0x105fbda30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10602a228>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fd45358f8c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x105f729f0>, '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 0x105cd1cd8>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x105f3c990>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'XPC_SERVICE_NAME': '0', 'HOME': '/Users/cltbld', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 'NO_EM_RESTART': '1', 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 'XPCOM_DEBUG_BREAK': 'warn', 'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.hzmkYpjbIV/Render', 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 'VERSIONER_PYTHON_VERSION': '2.7', 'XPC_FLAGS': '0x0', 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 'MOZ_NO_REMOTE': '1', 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.OlDG3iec1b/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/', '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0', 'PWD': '/builds/slave/test', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'PAGER': '/bin/cat'}}, attempt #1
14:01:26 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
14:01:26 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
14:01:26 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.hzmkYpjbIV/Render',
14:01:26 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared',
14:01:26 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared',
14:01:26 INFO - 'HOME': '/Users/cltbld',
14:01:26 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true',
14:01:26 INFO - 'LOGNAME': 'cltbld',
14:01:26 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
14:01:26 INFO - 'MOZ_NO_REMOTE': '1',
14:01:26 INFO - 'NO_EM_RESTART': '1',
14:01:26 INFO - 'PAGER': '/bin/cat',
14:01:26 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11',
14:01:26 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
14:01:26 INFO - 'PWD': '/builds/slave/test',
14:01:26 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg',
14:01:26 INFO - 'SHELL': '/bin/bash',
14:01:26 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.OlDG3iec1b/Listeners',
14:01:26 INFO - 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/',
14:01:26 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log',
14:01:26 INFO - 'USER': 'cltbld',
14:01:26 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no',
14:01:26 INFO - 'VERSIONER_PYTHON_VERSION': '2.7',
14:01:26 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
14:01:26 INFO - 'XPC_FLAGS': '0x0',
14:01:26 INFO - 'XPC_SERVICE_NAME': '0',
14:01:26 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'}
14:01:27 INFO - Ignoring indexes: https://pypi.python.org/simple/
14:01:27 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
14:01:27 INFO - Cleaning up...
14:01:27 INFO - Return code: 0
14:01:27 INFO - Installing psutil>=0.7.1 into virtualenv /builds/slave/test/build/venv
14:01:27 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')]}
14:01:27 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
14:01:27 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
14:01:27 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')]}
14:01:27 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
14:01:27 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
14:01:27 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 0x105fbda30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10602a228>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fd45358f8c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x105f729f0>, '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 0x105cd1cd8>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x105f3c990>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'XPC_SERVICE_NAME': '0', 'HOME': '/Users/cltbld', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 'NO_EM_RESTART': '1', 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 'XPCOM_DEBUG_BREAK': 'warn', 'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.hzmkYpjbIV/Render', 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 'VERSIONER_PYTHON_VERSION': '2.7', 'XPC_FLAGS': '0x0', 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 'MOZ_NO_REMOTE': '1', 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.OlDG3iec1b/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/', '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0', 'PWD': '/builds/slave/test', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'PAGER': '/bin/cat'}}, attempt #1
14:01:27 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
14:01:27 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
14:01:27 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.hzmkYpjbIV/Render',
14:01:27 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared',
14:01:27 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared',
14:01:27 INFO - 'HOME': '/Users/cltbld',
14:01:27 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true',
14:01:27 INFO - 'LOGNAME': 'cltbld',
14:01:27 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
14:01:27 INFO - 'MOZ_NO_REMOTE': '1',
14:01:27 INFO - 'NO_EM_RESTART': '1',
14:01:27 INFO - 'PAGER': '/bin/cat',
14:01:27 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11',
14:01:27 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
14:01:27 INFO - 'PWD': '/builds/slave/test',
14:01:27 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg',
14:01:27 INFO - 'SHELL': '/bin/bash',
14:01:27 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.OlDG3iec1b/Listeners',
14:01:27 INFO - 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/',
14:01:27 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log',
14:01:27 INFO - 'USER': 'cltbld',
14:01:27 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no',
14:01:27 INFO - 'VERSIONER_PYTHON_VERSION': '2.7',
14:01:27 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
14:01:27 INFO - 'XPC_FLAGS': '0x0',
14:01:27 INFO - 'XPC_SERVICE_NAME': '0',
14:01:27 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'}
14:01:27 INFO - Ignoring indexes: https://pypi.python.org/simple/
14:01:27 INFO - Downloading/unpacking psutil>=0.7.1
14:01:27 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
14:01:27 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
14:01:27 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
14:01:27 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
14:01:27 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
14:01:27 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
14:01:29 INFO - Creating supposed download cache at /builds/slave/test/build/venv/cache
14:01:29 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fpsutil-3.1.1.tar.gz
14:01:29 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/psutil/setup.py) egg_info for package psutil
14:01:29 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build'
14:01:29 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects
...
14:01:29 INFO - Installing collected packages: psutil
14:01:29 INFO - Running setup.py install for psutil
14:01:30 INFO - building 'psutil._psutil_osx' extension
14:01:30 INFO - gcc -fno-strict-aliasing -g -O2 -DNDEBUG -g -fwrapv -O3 -Wall -Wstrict-prototypes -DPSUTIL_VERSION=311 -I/tools/python27/include/python2.7 -c psutil/_psutil_osx.c -o build/temp.macosx-10.10-x86_64-2.7/psutil/_psutil_osx.o
14:01:31 INFO - gcc -fno-strict-aliasing -g -O2 -DNDEBUG -g -fwrapv -O3 -Wall -Wstrict-prototypes -DPSUTIL_VERSION=311 -I/tools/python27/include/python2.7 -c psutil/_psutil_common.c -o build/temp.macosx-10.10-x86_64-2.7/psutil/_psutil_common.o
14:01:31 INFO - gcc -fno-strict-aliasing -g -O2 -DNDEBUG -g -fwrapv -O3 -Wall -Wstrict-prototypes -DPSUTIL_VERSION=311 -I/tools/python27/include/python2.7 -c psutil/arch/osx/process_info.c -o build/temp.macosx-10.10-x86_64-2.7/psutil/arch/osx/process_info.o
14:01:31 INFO - gcc -bundle -bundle_loader /tools/python27/bin/python2.7 build/temp.macosx-10.10-x86_64-2.7/psutil/_psutil_osx.o build/temp.macosx-10.10-x86_64-2.7/psutil/_psutil_common.o build/temp.macosx-10.10-x86_64-2.7/psutil/arch/osx/process_info.o -o build/lib.macosx-10.10-x86_64-2.7/psutil/_psutil_osx.so -framework CoreFoundation -framework IOKit
14:01:32 INFO - building 'psutil._psutil_posix' extension
14:01:32 INFO - gcc -fno-strict-aliasing -g -O2 -DNDEBUG -g -fwrapv -O3 -Wall -Wstrict-prototypes -I/tools/python27/include/python2.7 -c psutil/_psutil_posix.c -o build/temp.macosx-10.10-x86_64-2.7/psutil/_psutil_posix.o
14:01:32 WARNING - psutil/_psutil_posix.c:403:11: warning: implicit declaration of function 'ioctl' is invalid in C99 [-Wimplicit-function-declaration]
14:01:32 INFO - ret = ioctl(sock, SIOCGIFFLAGS, &ifr);
14:01:32 INFO - ^
14:01:32 INFO - 1 warning generated.
14:01:32 INFO - gcc -bundle -bundle_loader /tools/python27/bin/python2.7 build/temp.macosx-10.10-x86_64-2.7/psutil/_psutil_posix.o -o build/lib.macosx-10.10-x86_64-2.7/psutil/_psutil_posix.so
14:01:32 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build'
14:01:32 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ...
14:01:32 INFO - Successfully installed psutil
14:01:32 INFO - Cleaning up...
14:01:32 INFO - Return code: 0
14:01:32 INFO - Installing mozsystemmonitor==0.0.0 into virtualenv /builds/slave/test/build/venv
14:01:32 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
14:01:32 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
14:01:32 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
14:01:32 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
14:01:32 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
14:01:32 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
14:01:32 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--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 0x105fbda30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10602a228>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fd45358f8c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x105f729f0>, '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 0x105cd1cd8>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x105f3c990>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'XPC_SERVICE_NAME': '0', 'HOME': '/Users/cltbld', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 'NO_EM_RESTART': '1', 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 'XPCOM_DEBUG_BREAK': 'warn', 'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.hzmkYpjbIV/Render', 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 'VERSIONER_PYTHON_VERSION': '2.7', 'XPC_FLAGS': '0x0', 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 'MOZ_NO_REMOTE': '1', 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.OlDG3iec1b/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/', '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0', 'PWD': '/builds/slave/test', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'PAGER': '/bin/cat'}}, attempt #1
14:01:32 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
14:01:32 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
14:01:32 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.hzmkYpjbIV/Render',
14:01:32 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared',
14:01:32 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared',
14:01:32 INFO - 'HOME': '/Users/cltbld',
14:01:32 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true',
14:01:32 INFO - 'LOGNAME': 'cltbld',
14:01:32 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
14:01:32 INFO - 'MOZ_NO_REMOTE': '1',
14:01:32 INFO - 'NO_EM_RESTART': '1',
14:01:32 INFO - 'PAGER': '/bin/cat',
14:01:32 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11',
14:01:32 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
14:01:32 INFO - 'PWD': '/builds/slave/test',
14:01:32 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg',
14:01:32 INFO - 'SHELL': '/bin/bash',
14:01:32 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.OlDG3iec1b/Listeners',
14:01:32 INFO - 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/',
14:01:32 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log',
14:01:32 INFO - 'USER': 'cltbld',
14:01:32 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no',
14:01:32 INFO - 'VERSIONER_PYTHON_VERSION': '2.7',
14:01:32 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
14:01:32 INFO - 'XPC_FLAGS': '0x0',
14:01:32 INFO - 'XPC_SERVICE_NAME': '0',
14:01:32 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'}
14:01:32 INFO - Ignoring indexes: https://pypi.python.org/simple/
14:01:32 INFO - Downloading/unpacking mozsystemmonitor==0.0.0
14:01:32 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
14:01:32 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
14:01:32 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
14:01:32 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
14:01:32 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
14:01:32 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
14:01:35 INFO - Downloading mozsystemmonitor-0.0.tar.gz
14:01:35 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fmozsystemmonitor-0.0.tar.gz
14:01:35 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/mozsystemmonitor/setup.py) egg_info for package mozsystemmonitor
14:01:35 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=0.7.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.0.0)
14:01:35 INFO - Installing collected packages: mozsystemmonitor
14:01:35 INFO - Running setup.py install for mozsystemmonitor
14:01:35 INFO - Successfully installed mozsystemmonitor
14:01:35 INFO - Cleaning up...
14:01:35 INFO - Return code: 0
14:01:35 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv
14:01:35 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')]}
14:01:35 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
14:01:35 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
14:01:35 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')]}
14:01:35 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
14:01:35 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
14:01:35 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 0x105fbda30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10602a228>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fd45358f8c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x105f729f0>, '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 0x105cd1cd8>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x105f3c990>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'XPC_SERVICE_NAME': '0', 'HOME': '/Users/cltbld', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 'NO_EM_RESTART': '1', 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 'XPCOM_DEBUG_BREAK': 'warn', 'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.hzmkYpjbIV/Render', 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 'VERSIONER_PYTHON_VERSION': '2.7', 'XPC_FLAGS': '0x0', 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 'MOZ_NO_REMOTE': '1', 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.OlDG3iec1b/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/', '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0', 'PWD': '/builds/slave/test', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'PAGER': '/bin/cat'}}, attempt #1
14:01:35 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
14:01:35 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
14:01:35 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.hzmkYpjbIV/Render',
14:01:35 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared',
14:01:35 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared',
14:01:35 INFO - 'HOME': '/Users/cltbld',
14:01:35 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true',
14:01:35 INFO - 'LOGNAME': 'cltbld',
14:01:35 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
14:01:35 INFO - 'MOZ_NO_REMOTE': '1',
14:01:35 INFO - 'NO_EM_RESTART': '1',
14:01:35 INFO - 'PAGER': '/bin/cat',
14:01:35 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11',
14:01:35 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
14:01:35 INFO - 'PWD': '/builds/slave/test',
14:01:35 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg',
14:01:35 INFO - 'SHELL': '/bin/bash',
14:01:35 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.OlDG3iec1b/Listeners',
14:01:35 INFO - 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/',
14:01:35 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log',
14:01:35 INFO - 'USER': 'cltbld',
14:01:35 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no',
14:01:35 INFO - 'VERSIONER_PYTHON_VERSION': '2.7',
14:01:35 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
14:01:35 INFO - 'XPC_FLAGS': '0x0',
14:01:35 INFO - 'XPC_SERVICE_NAME': '0',
14:01:35 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'}
14:01:35 INFO - Ignoring indexes: https://pypi.python.org/simple/
14:01:35 INFO - Downloading/unpacking blobuploader==1.2.4
14:01:35 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
14:01:35 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
14:01:35 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
14:01:35 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
14:01:35 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
14:01:35 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
14:01:38 INFO - Downloading blobuploader-1.2.4.tar.gz
14:01:38 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fblobuploader-1.2.4.tar.gz
14:01:38 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blobuploader/setup.py) egg_info for package blobuploader
14:01:38 INFO - Downloading/unpacking requests==1.2.3. (from blobuploader==1.2.4)
14:01:38 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
14:01:38 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
14:01:38 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
14:01:38 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
14:01:38 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
14:01:38 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
14:01:38 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Frequests-1.2.3.tar.gz
14:01:38 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests
14:01:38 INFO - Downloading/unpacking docopt==0.6.1 (from blobuploader==1.2.4)
14:01:38 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
14:01:38 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
14:01:38 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
14:01:38 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
14:01:38 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
14:01:38 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
14:01:39 INFO - Downloading docopt-0.6.1.tar.gz
14:01:39 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fdocopt-0.6.1.tar.gz
14:01:39 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/docopt/setup.py) egg_info for package docopt
14:01:39 INFO - Installing collected packages: blobuploader, requests, docopt
14:01:39 INFO - Running setup.py install for blobuploader
14:01:39 INFO - changing mode of build/scripts-2.7/blobberc.py from 664 to 775
14:01:39 INFO - changing mode of /builds/slave/test/build/venv/bin/blobberc.py to 775
14:01:39 INFO - Running setup.py install for requests
14:01:40 INFO - Running setup.py install for docopt
14:01:40 INFO - Successfully installed blobuploader requests docopt
14:01:40 INFO - Cleaning up...
14:01:40 INFO - Return code: 0
14:01:40 INFO - Installing None into virtualenv /builds/slave/test/build/venv
14:01:40 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
14:01:40 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
14:01:40 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
14:01:40 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
14:01:40 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
14:01:40 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
14:01:40 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 0x105fbda30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10602a228>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fd45358f8c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x105f729f0>, '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 0x105cd1cd8>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x105f3c990>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build/tests/config', 'env': {'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'XPC_SERVICE_NAME': '0', 'HOME': '/Users/cltbld', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 'NO_EM_RESTART': '1', 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 'XPCOM_DEBUG_BREAK': 'warn', 'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.hzmkYpjbIV/Render', 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 'VERSIONER_PYTHON_VERSION': '2.7', 'XPC_FLAGS': '0x0', 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 'MOZ_NO_REMOTE': '1', 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.OlDG3iec1b/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/', '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0', 'PWD': '/builds/slave/test', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'PAGER': '/bin/cat'}}, attempt #1
14:01:40 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
14:01:40 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
14:01:40 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.hzmkYpjbIV/Render',
14:01:40 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared',
14:01:40 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared',
14:01:40 INFO - 'HOME': '/Users/cltbld',
14:01:40 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true',
14:01:40 INFO - 'LOGNAME': 'cltbld',
14:01:40 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
14:01:40 INFO - 'MOZ_NO_REMOTE': '1',
14:01:40 INFO - 'NO_EM_RESTART': '1',
14:01:40 INFO - 'PAGER': '/bin/cat',
14:01:40 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11',
14:01:40 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
14:01:40 INFO - 'PWD': '/builds/slave/test',
14:01:40 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg',
14:01:40 INFO - 'SHELL': '/bin/bash',
14:01:40 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.OlDG3iec1b/Listeners',
14:01:40 INFO - 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/',
14:01:40 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log',
14:01:40 INFO - 'USER': 'cltbld',
14:01:40 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no',
14:01:40 INFO - 'VERSIONER_PYTHON_VERSION': '2.7',
14:01:40 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
14:01:40 INFO - 'XPC_FLAGS': '0x0',
14:01:40 INFO - 'XPC_SERVICE_NAME': '0',
14:01:40 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'}
14:01:40 INFO - Ignoring indexes: https://pypi.python.org/simple/
14:01:40 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser
14:01:40 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-DuNfaL-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser
14:01:40 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash
14:01:40 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-RY1ojX-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash
14:01:40 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug
14:01:40 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-g6L2pT-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug
14:01:40 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice
14:01:40 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-2ZUfZl-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice
14:01:41 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile
14:01:41 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-IC1LhK-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile
14:01:41 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd
14:01:41 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-VTy_Y3-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd
14:01:41 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo
14:01:41 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-TYwqep-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo
14:01:41 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall
14:01:41 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-_gooNk-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall
14:01:41 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak
14:01:41 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-JCG7lf-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak
14:01:41 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog
14:01:41 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-2BbAOx-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog
14:01:41 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork
14:01:41 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-qIhBYZ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork
14:01:41 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess
14:01:41 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-C5dvNU-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess
14:01:41 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile
14:01:41 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-9dTK2A-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile
14:01:42 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner
14:01:42 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-EByyS1-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner
14:01:42 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot
14:01:42 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-l0xkbF-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot
14:01:42 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest
14:01:42 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-gqI2yj-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest
14:01:42 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion
14:01:42 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-YrTHu9-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion
14:01:42 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion
14:01:42 INFO - Running setup.py install for manifestparser
14:01:42 INFO - Installing manifestparser script to /builds/slave/test/build/venv/bin
14:01:42 INFO - Running setup.py install for mozcrash
14:01:42 INFO - Running setup.py install for mozdebug
14:01:43 INFO - Running setup.py install for mozdevice
14:01:43 INFO - Installing sutini script to /builds/slave/test/build/venv/bin
14:01:43 INFO - Installing dm script to /builds/slave/test/build/venv/bin
14:01:43 INFO - Running setup.py install for mozfile
14:01:43 INFO - Running setup.py install for mozhttpd
14:01:43 INFO - Installing mozhttpd script to /builds/slave/test/build/venv/bin
14:01:43 INFO - Running setup.py install for mozinfo
14:01:43 INFO - Installing mozinfo script to /builds/slave/test/build/venv/bin
14:01:43 INFO - Running setup.py install for mozInstall
14:01:43 INFO - Installing moz_remove_from_system script to /builds/slave/test/build/venv/bin
14:01:43 INFO - Installing mozuninstall script to /builds/slave/test/build/venv/bin
14:01:43 INFO - Installing mozinstall script to /builds/slave/test/build/venv/bin
14:01:43 INFO - Installing moz_add_to_system script to /builds/slave/test/build/venv/bin
14:01:43 INFO - Running setup.py install for mozleak
14:01:44 INFO - Running setup.py install for mozlog
14:01:44 INFO - Installing structlog script to /builds/slave/test/build/venv/bin
14:01:44 INFO - Running setup.py install for moznetwork
14:01:44 INFO - Installing moznetwork script to /builds/slave/test/build/venv/bin
14:01:44 INFO - Running setup.py install for mozprocess
14:01:44 INFO - Running setup.py install for mozprofile
14:01:44 INFO - Installing mozprofile script to /builds/slave/test/build/venv/bin
14:01:44 INFO - Installing diff-profiles script to /builds/slave/test/build/venv/bin
14:01:44 INFO - Installing view-profile script to /builds/slave/test/build/venv/bin
14:01:44 INFO - Running setup.py install for mozrunner
14:01:44 INFO - Installing mozrunner script to /builds/slave/test/build/venv/bin
14:01:44 INFO - Running setup.py install for mozscreenshot
14:01:45 INFO - Running setup.py install for moztest
14:01:45 INFO - Running setup.py install for mozversion
14:01:45 INFO - Installing mozversion script to /builds/slave/test/build/venv/bin
14:01:45 INFO - Successfully installed manifestparser mozcrash mozdebug mozdevice mozfile mozhttpd mozinfo mozInstall mozleak mozlog moznetwork mozprocess mozprofile mozrunner mozscreenshot moztest mozversion
14:01:45 INFO - Cleaning up...
14:01:45 INFO - Return code: 0
14:01:45 INFO - Installing None into virtualenv /builds/slave/test/build/venv
14:01: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')]}
14:01:45 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
14:01:45 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
14:01: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')]}
14:01:45 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
14:01:45 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
14:01:45 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 0x105fbda30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10602a228>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fd45358f8c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x105f729f0>, '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 0x105cd1cd8>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x105f3c990>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build/tests/config', 'env': {'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'XPC_SERVICE_NAME': '0', 'HOME': '/Users/cltbld', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 'NO_EM_RESTART': '1', 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 'XPCOM_DEBUG_BREAK': 'warn', 'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.hzmkYpjbIV/Render', 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 'VERSIONER_PYTHON_VERSION': '2.7', 'XPC_FLAGS': '0x0', 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 'MOZ_NO_REMOTE': '1', 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.OlDG3iec1b/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/', '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0', 'PWD': '/builds/slave/test', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'PAGER': '/bin/cat'}}, attempt #1
14:01:45 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
14:01:45 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
14:01:45 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.hzmkYpjbIV/Render',
14:01:45 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared',
14:01:45 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared',
14:01:45 INFO - 'HOME': '/Users/cltbld',
14:01:45 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true',
14:01:45 INFO - 'LOGNAME': 'cltbld',
14:01:45 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
14:01:45 INFO - 'MOZ_NO_REMOTE': '1',
14:01:45 INFO - 'NO_EM_RESTART': '1',
14:01:45 INFO - 'PAGER': '/bin/cat',
14:01:45 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11',
14:01:45 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
14:01:45 INFO - 'PWD': '/builds/slave/test',
14:01:45 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg',
14:01:45 INFO - 'SHELL': '/bin/bash',
14:01:45 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.OlDG3iec1b/Listeners',
14:01:45 INFO - 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/',
14:01:45 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log',
14:01:45 INFO - 'USER': 'cltbld',
14:01:45 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no',
14:01:45 INFO - 'VERSIONER_PYTHON_VERSION': '2.7',
14:01:45 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
14:01:45 INFO - 'XPC_FLAGS': '0x0',
14:01:45 INFO - 'XPC_SERVICE_NAME': '0',
14:01:45 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'}
14:01:45 INFO - Ignoring indexes: https://pypi.python.org/simple/
14:01:45 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser
14:01:45 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-9YWMej-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser
14:01:45 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))
14:01:45 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash
14:01:45 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-XcJ69Z-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash
14:01:45 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))
14:01:45 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug
14:01:45 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-5CsNgQ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug
14:01:46 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))
14:01:46 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice
14:01:46 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-EriSws-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice
14:01:46 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdevice==0.46 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))
14:01:46 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile
14:01:46 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-fM1xTF-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile
14:01:46 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))
14:01:46 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd
14:01:46 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-kWYhMN-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd
14:01:46 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))
14:01:46 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo
14:01:46 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-BE7hSF-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo
14:01:46 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo==0.8 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))
14:01:46 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall
14:01:46 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-h4cmN0-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall
14:01:46 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))
14:01:46 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak
14:01:46 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-MMVwCP-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak
14:01:46 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))
14:01:46 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog
14:01:46 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-mHeoGJ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog
14:01:46 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))
14:01:46 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork
14:01:46 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-9PhWnF-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork
14:01:47 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))
14:01:47 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess
14:01:47 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-Tsiq0c-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess
14:01:47 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))
14:01:47 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile
14:01:47 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-12ToQO-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile
14:01:47 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))
14:01:47 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner
14:01:47 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-VXhjyZ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner
14:01:47 INFO - Requirement already satisfied (use --upgrade to upgrade): mozrunner==6.10 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))
14:01:47 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot
14:01:47 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-BuzfmV-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot
14:01:47 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))
14:01:47 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest
14:01:47 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-08KfGk-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest
14:01:47 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))
14:01:47 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion
14:01:47 INFO - Running setup.py (path:/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/pip-VAugwR-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion
14:01:47 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))
14:01:47 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))
14:01:47 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))
14:01:47 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))
14:01:47 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.46->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4))
14:01:47 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.46->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4))
14:01:47 INFO - Downloading/unpacking blessings>=1.3 (from mozlog==3.0->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10))
14:01:47 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
14:01:47 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
14:01:47 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
14:01:47 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
14:01:47 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
14:01:47 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
14:01:50 INFO - Downloading blessings-1.5.1.tar.gz
14:01:50 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
14:01:50 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blessings/setup.py) egg_info for package blessings
14:01:50 INFO - Installing collected packages: blessings
14:01:50 INFO - Running setup.py install for blessings
14:01:50 INFO - Successfully installed blessings
14:01:50 INFO - Cleaning up...
14:01:50 INFO - Return code: 0
14:01:50 INFO - Done creating virtualenv /builds/slave/test/build/venv.
14:01:50 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze']
14:01:50 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze
14:01:50 INFO - Reading from file tmpfile_stdout
14:01:50 INFO - Current package versions:
14:01:50 INFO - blessings == 1.5.1
14:01:50 INFO - blobuploader == 1.2.4
14:01:50 INFO - docopt == 0.6.1
14:01:50 INFO - manifestparser == 1.1
14:01:50 INFO - mozInstall == 1.12
14:01:50 INFO - mozcrash == 0.16
14:01:50 INFO - mozdebug == 0.1
14:01:50 INFO - mozdevice == 0.46
14:01:50 INFO - mozfile == 1.2
14:01:50 INFO - mozhttpd == 0.7
14:01:50 INFO - mozinfo == 0.8
14:01:50 INFO - mozleak == 0.1
14:01:50 INFO - mozlog == 3.0
14:01:50 INFO - moznetwork == 0.27
14:01:50 INFO - mozprocess == 0.22
14:01:50 INFO - mozprofile == 0.27
14:01:50 INFO - mozrunner == 6.10
14:01:50 INFO - mozscreenshot == 0.1
14:01:50 INFO - mozsystemmonitor == 0.0
14:01:50 INFO - moztest == 0.7
14:01:50 INFO - mozversion == 1.4
14:01:50 INFO - psutil == 3.1.1
14:01:50 INFO - requests == 1.2.3
14:01:50 INFO - wsgiref == 0.1.2
14:01:50 INFO - Installing None into virtualenv /builds/slave/test/build/venv
14:01:50 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
14:01:50 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
14:01:50 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
14:01:50 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]}
14:01:50 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
14:01:50 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub
14:01:50 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 0x105fbda30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10602a228>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fd45358f8c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x105f729f0>, '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 0x105cd1cd8>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x105f3c990>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build/tests/talos', 'env': {'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'XPC_SERVICE_NAME': '0', 'HOME': '/Users/cltbld', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 'NO_EM_RESTART': '1', 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 'XPCOM_DEBUG_BREAK': 'warn', 'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.hzmkYpjbIV/Render', 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 'VERSIONER_PYTHON_VERSION': '2.7', 'XPC_FLAGS': '0x0', 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 'MOZ_NO_REMOTE': '1', 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.OlDG3iec1b/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/', '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0', 'PWD': '/builds/slave/test', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'PAGER': '/bin/cat'}}, attempt #1
14:01:50 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
14:01:50 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
14:01:50 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.hzmkYpjbIV/Render',
14:01:50 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared',
14:01:50 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared',
14:01:50 INFO - 'HOME': '/Users/cltbld',
14:01:50 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true',
14:01:50 INFO - 'LOGNAME': 'cltbld',
14:01:50 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
14:01:50 INFO - 'MOZ_NO_REMOTE': '1',
14:01:50 INFO - 'NO_EM_RESTART': '1',
14:01:50 INFO - 'PAGER': '/bin/cat',
14:01:50 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11',
14:01:50 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
14:01:50 INFO - 'PWD': '/builds/slave/test',
14:01:50 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg',
14:01:50 INFO - 'SHELL': '/bin/bash',
14:01:50 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.OlDG3iec1b/Listeners',
14:01:50 INFO - 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/',
14:01:50 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log',
14:01:50 INFO - 'USER': 'cltbld',
14:01:50 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no',
14:01:50 INFO - 'VERSIONER_PYTHON_VERSION': '2.7',
14:01:50 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
14:01:50 INFO - 'XPC_FLAGS': '0x0',
14:01:50 INFO - 'XPC_SERVICE_NAME': '0',
14:01:50 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'}
14:01:51 INFO - Ignoring indexes: https://pypi.python.org/simple/
14:01:51 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))
14:01:51 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))
14:01:51 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))
14:01:51 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))
14:01:51 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))
14:01:51 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))
14:01:51 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))
14:01:51 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))
14:01:51 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))
14:01:51 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))
14:01:51 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))
14:01:51 INFO - Cleaning up...
14:01:51 INFO - Return code: 0
14:01:51 INFO - Running post-action listener: _resource_record_post_action
14:01:51 INFO - Running post-action listener: _start_resource_monitoring
14:01:51 INFO - Starting resource monitoring.
14:01:51 INFO - #####
14:01:51 INFO - ##### Running install step.
14:01:51 INFO - #####
14:01:51 INFO - Running pre-action listener: _resource_record_pre_action
14:01:51 INFO - Running main action method: install
14:01:51 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze']
14:01:51 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze
14:01:51 INFO - Reading from file tmpfile_stdout
14:01:51 INFO - Detecting whether we're running mozinstall >=1.0...
14:01:51 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h']
14:01:51 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h
14:01:51 INFO - Reading from file tmpfile_stdout
14:01:51 INFO - Output received:
14:01:51 INFO - Usage: mozinstall [options] installer
14:01:51 INFO - Options:
14:01:51 INFO - -h, --help show this help message and exit
14:01:51 INFO - -d DEST, --destination=DEST
14:01:51 INFO - Directory to install application into. [default:
14:01:51 INFO - "/builds/slave/test"]
14:01:51 INFO - --app=APP Application being installed. [default: firefox]
14:01:51 INFO - mkdir: /builds/slave/test/build/application
14:01:51 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '/builds/slave/test/build/firefox-44.0a1.en-US.mac.dmg', '--destination', '/builds/slave/test/build/application']
14:01:51 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall /builds/slave/test/build/firefox-44.0a1.en-US.mac.dmg --destination /builds/slave/test/build/application
14:02:27 INFO - Reading from file tmpfile_stdout
14:02:27 INFO - Output received:
14:02:27 INFO - /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox
14:02:27 INFO - Running post-action listener: _resource_record_post_action
14:02:27 INFO - #####
14:02:27 INFO - ##### Running run-tests step.
14:02:27 INFO - #####
14:02:27 INFO - Running pre-action listener: _resource_record_pre_action
14:02:27 INFO - Running main action method: run_tests
14:02:27 INFO - Running pre test command check_screen_resolution with 'bash -c screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'
14:02:27 INFO - Running command: ['bash', '-c', 'screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'] in /builds/slave/test/build
14:02:27 INFO - Copy/paste: bash -c "screenresolution get && screenresolution list && system_profiler SPDisplaysDataType"
14:02:27 INFO - 2015-10-23 14:02:27.618 screenresolution[1631:7514] starting screenresolution argv=screenresolution get
14:02:27 INFO - 2015-10-23 14:02:27.621 screenresolution[1631:7514] Display 0: 1600x1200x32@60
14:02:27 INFO - 2015-10-23 14:02:27.628 screenresolution[1632:7516] starting screenresolution argv=screenresolution list
14:02:27 INFO - Available Modes on Display 0
14:02:27 INFO - 1600x1200x32@60 1152x870x32@75 1280x1024x32@75
14:02:27 INFO - 1024x768x32@75 1024x768x32@70 1024x768x32@60
14:02:27 INFO - 800x600x32@75 800x600x32@60 640x480x32@75
14:02:27 INFO - 640x480x32@60 1280x1024x32@60 1280x960x32@60
14:02:27 INFO - 1280x960x32@75 1344x1008x32@60 Graphics/Displays:
14:02:27 INFO - Intel HD Graphics 3000:
14:02:27 INFO - Chipset Model: Intel HD Graphics 3000
14:02:27 INFO - Type: GPU
14:02:27 INFO - Bus: Built-In
14:02:27 INFO - VRAM (Total): 512 MB
14:02:27 INFO - VRAM (Dynamic, Max): 10
14:02:27 INFO - Vendor: Intel (0x8086)
14:02:27 INFO - Device ID: 0x0116
14:02:27 INFO - Revision ID: 0x0009
14:02:27 INFO - Displays:
14:02:27 INFO - Display:
14:02:27 INFO - Resolution: 1600 x 1200 @ 60 Hz
14:02:27 INFO - Pixel Depth: 32-Bit Color (ARGB8888)
14:02:27 INFO - Display Serial Number: 1600x1200 60
14:02:27 INFO - Main Display: Yes
14:02:27 INFO - Mirror: Off
14:02:27 INFO - Online: Yes
14:02:27 INFO - Rotation: Supported
14:02:27 INFO - Return code: 0
14:02:27 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version']
14:02:27 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version
14:02:27 INFO - Python 2.7.3
14:02:27 INFO - Return code: 0
14:02:27 INFO - grabbing minidump binary from tooltool
14:02:27 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')]}
14:02:27 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/macosx64/releng.manifest', '-o', '-c', '/builds/tooltool_cache'],), kwargs: {'error_list': [{'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x105f729f0>, '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 0x105cd1cd8>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x105f3c990>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1
14:02:27 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/macosx64/releng.manifest', '-o', '-c', '/builds/tooltool_cache'] in /builds/slave/test/build
14:02:27 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/macosx64/releng.manifest -o -c /builds/tooltool_cache
14:02:27 INFO - INFO - File macosx64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache
14:02:27 INFO - Return code: 0
14:02:27 INFO - Chmoding /builds/slave/test/build/macosx64-minidump_stackwalk to 0755
14:02:27 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir
14:02:27 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir
14:02:27 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/macosx64-minidump_stackwalk
14:02:27 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir
14:02:27 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--debug', '--branchName', 'Fx-Team', '--suite', 'other', '--executablePath', '/builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.crashreporter-symbols.zip', '--title', 't-yosemite-r5-0016', '--webServer', 'localhost'] in /builds/slave/test/build
14:02:27 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/tests/talos/talos/run_tests.py --debug --branchName Fx-Team --suite other --executablePath /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox --symbolsPath https://queue.taskcluster.net/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.crashreporter-symbols.zip --title t-yosemite-r5-0016 --webServer localhost
14:02:27 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.hzmkYpjbIV/Render',
14:02:27 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared',
14:02:27 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared',
14:02:27 INFO - 'HOME': '/Users/cltbld',
14:02:27 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true',
14:02:27 INFO - 'LOGNAME': 'cltbld',
14:02:27 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir',
14:02:27 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/macosx64-minidump_stackwalk',
14:02:27 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
14:02:27 INFO - 'MOZ_NO_REMOTE': '1',
14:02:27 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir',
14:02:27 INFO - 'NO_EM_RESTART': '1',
14:02:27 INFO - 'PAGER': '/bin/cat',
14:02:27 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11',
14:02:27 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
14:02:27 INFO - 'PWD': '/builds/slave/test',
14:02:27 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos',
14:02:27 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg',
14:02:27 INFO - 'SHELL': '/bin/bash',
14:02:27 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.OlDG3iec1b/Listeners',
14:02:28 INFO - 'TMPDIR': '/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/',
14:02:28 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log',
14:02:28 INFO - 'USER': 'cltbld',
14:02:28 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no',
14:02:28 INFO - 'VERSIONER_PYTHON_VERSION': '2.7',
14:02:28 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
14:02:28 INFO - 'XPC_FLAGS': '0x0',
14:02:28 INFO - 'XPC_SERVICE_NAME': '0',
14:02:28 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'}
14:02:28 INFO - Calling ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--debug', '--branchName', 'Fx-Team', '--suite', 'other', '--executablePath', '/builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.crashreporter-symbols.zip', '--title', 't-yosemite-r5-0016', '--webServer', 'localhost'] with output_timeout 3600
14:02:28 INFO - mozversion INFO | application_buildid: 20151023121232
14:02:28 INFO - mozversion INFO | application_changeset: ccb7bb578fb15e0fe344b0e9a3b3628faed8bedc
14:02:28 INFO - mozversion INFO | application_display_name: Nightly
14:02:28 INFO - mozversion INFO | application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384}
14:02:28 INFO - mozversion INFO | application_name: Firefox
14:02:28 INFO - mozversion INFO | application_remotingname: firefox
14:02:28 INFO - mozversion INFO | application_repository: https://hg.mozilla.org/integration/fx-team
14:02:28 INFO - mozversion INFO | application_vendor: Mozilla
14:02:28 INFO - mozversion INFO | application_version: 44.0a1
14:02:28 INFO - mozversion INFO | platform_buildid: 20151023121232
14:02:28 INFO - mozversion INFO | platform_changeset: ccb7bb578fb15e0fe344b0e9a3b3628faed8bedc
14:02:28 INFO - mozversion INFO | platform_repository: https://hg.mozilla.org/integration/fx-team
14:02:28 INFO - mozversion INFO | platform_version: 44.0a1
14:02:28 INFO - 2015-10-23 14:02:28,326 DEBUG : using testdate: 1445634148
14:02:28 INFO - 2015-10-23 14:02:28,326 DEBUG : actual date: 1445634148
14:02:28 INFO - 2015-10-23 14:02:28,337 INFO : starting webserver on 'localhost:49269'
14:02:28 INFO - 2015-10-23 14:02:28,338 INFO : Starting test suite t-yosemite-r5-0016
14:02:28 INFO - 2015-10-23 14:02:28,338 INFO : Starting test a11yr
14:02:28 INFO - 2015-10-23 14:02:28,338 DEBUG : operating with platform_type : mac_
14:02:28 INFO - 2015-10-23 14:02:28,339 INFO : Initialising browser for a11yr test...
14:02:28 INFO - 2015-10-23 14:02:28,353 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpjDgKme/profile http://localhost:49269/getInfo.html
14:02:31 INFO - 2015-10-23 14:02:31,192 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
14:02:31 INFO - 2015-10-23 14:02:31,193 DEBUG : BROWSER_OUTPUT: colorDepth:24
14:02:31 INFO - 2015-10-23 14:02:31,193 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/689
14:02:31 INFO - 2015-10-23 14:02:31,193 DEBUG : BROWSER_OUTPUT: __metrics
14:02:31 INFO - 2015-10-23 14:02:31,210 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]
14:02:31 INFO - 2015-10-23 14:02:31,940 INFO : Browser initialized.
14:02:31 INFO - 2015-10-23 14:02:31,940 INFO : Running cycle 1/1 for a11yr test...
14:02:31 INFO - 2015-10-23 14:02:31,940 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpjDgKme/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/a11y/a11y.manifest.develop -tpchrome -tpmozafterpaint -tpnoisy -tpcycles 1 -tppagecycles 25
14:02:43 INFO - 2015-10-23 14:02:43,867 DEBUG : BROWSER_OUTPUT: RSS: Main: 222507008
14:02:43 INFO - 2015-10-23 14:02:43,867 DEBUG : BROWSER_OUTPUT:
14:02:45 INFO - 2015-10-23 14:02:45,038 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)
14:02:45 INFO - 2015-10-23 14:02:45,647 DEBUG : BROWSER_OUTPUT: RSS: Main: 274829312
14:02:45 INFO - 2015-10-23 14:02:45,647 DEBUG : BROWSER_OUTPUT:
14:02:46 INFO - 2015-10-23 14:02:46,866 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)
14:02:47 INFO - 2015-10-23 14:02:47,534 DEBUG : BROWSER_OUTPUT: RSS: Main: 289869824
14:02:47 INFO - 2015-10-23 14:02:47,534 DEBUG : BROWSER_OUTPUT:
14:02:48 INFO - 2015-10-23 14:02:48,643 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)
14:02:49 INFO - 2015-10-23 14:02:49,328 DEBUG : BROWSER_OUTPUT: RSS: Main: 289505280
14:02:49 INFO - 2015-10-23 14:02:49,328 DEBUG : BROWSER_OUTPUT:
14:02:50 INFO - 2015-10-23 14:02:50,550 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)
14:02:51 INFO - 2015-10-23 14:02:51,216 DEBUG : BROWSER_OUTPUT: RSS: Main: 291807232
14:02:51 INFO - 2015-10-23 14:02:51,216 DEBUG : BROWSER_OUTPUT:
14:02:52 INFO - 2015-10-23 14:02:52,420 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)
14:02:53 INFO - 2015-10-23 14:02:53,091 DEBUG : BROWSER_OUTPUT: RSS: Main: 290492416
14:02:53 INFO - 2015-10-23 14:02:53,091 DEBUG : BROWSER_OUTPUT:
14:02:54 INFO - 2015-10-23 14:02:54,319 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)
14:02:54 INFO - 2015-10-23 14:02:54,999 DEBUG : BROWSER_OUTPUT: RSS: Main: 291495936
14:02:54 INFO - 2015-10-23 14:02:54,999 DEBUG : BROWSER_OUTPUT:
14:02:56 INFO - 2015-10-23 14:02:56,222 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)
14:02:56 INFO - 2015-10-23 14:02:56,892 DEBUG : BROWSER_OUTPUT: RSS: Main: 291909632
14:02:56 INFO - 2015-10-23 14:02:56,892 DEBUG : BROWSER_OUTPUT:
14:02:58 INFO - 2015-10-23 14:02:58,120 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)
14:02:58 INFO - 2015-10-23 14:02:58,791 DEBUG : BROWSER_OUTPUT: RSS: Main: 293531648
14:02:58 INFO - 2015-10-23 14:02:58,791 DEBUG : BROWSER_OUTPUT:
14:03:00 INFO - 2015-10-23 14:03:00,047 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)
14:03:00 INFO - 2015-10-23 14:03:00,727 DEBUG : BROWSER_OUTPUT: RSS: Main: 292601856
14:03:00 INFO - 2015-10-23 14:03:00,727 DEBUG : BROWSER_OUTPUT:
14:03:01 INFO - 2015-10-23 14:03:01,921 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)
14:03:02 INFO - 2015-10-23 14:03:02,603 DEBUG : BROWSER_OUTPUT: RSS: Main: 294023168
14:03:02 INFO - 2015-10-23 14:03:02,603 DEBUG : BROWSER_OUTPUT:
14:03:03 INFO - 2015-10-23 14:03:03,833 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)
14:03:04 INFO - 2015-10-23 14:03:04,516 DEBUG : BROWSER_OUTPUT: RSS: Main: 293470208
14:03:04 INFO - 2015-10-23 14:03:04,516 DEBUG : BROWSER_OUTPUT:
14:03:05 INFO - 2015-10-23 14:03:05,744 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)
14:03:06 INFO - 2015-10-23 14:03:06,428 DEBUG : BROWSER_OUTPUT: RSS: Main: 293027840
14:03:06 INFO - 2015-10-23 14:03:06,429 DEBUG : BROWSER_OUTPUT:
14:03:07 INFO - 2015-10-23 14:03:07,562 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)
14:03:08 INFO - 2015-10-23 14:03:08,244 DEBUG : BROWSER_OUTPUT: RSS: Main: 292438016
14:03:08 INFO - 2015-10-23 14:03:08,244 DEBUG : BROWSER_OUTPUT:
14:03:09 INFO - 2015-10-23 14:03:09,500 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)
14:03:10 INFO - 2015-10-23 14:03:10,181 DEBUG : BROWSER_OUTPUT: RSS: Main: 293343232
14:03:10 INFO - 2015-10-23 14:03:10,181 DEBUG : BROWSER_OUTPUT:
14:03:11 INFO - 2015-10-23 14:03:11,311 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)
14:03:11 INFO - 2015-10-23 14:03:11,992 DEBUG : BROWSER_OUTPUT: RSS: Main: 293916672
14:03:11 INFO - 2015-10-23 14:03:11,992 DEBUG : BROWSER_OUTPUT:
14:03:13 INFO - 2015-10-23 14:03:13,236 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)
14:03:13 INFO - 2015-10-23 14:03:13,916 DEBUG : BROWSER_OUTPUT: RSS: Main: 294408192
14:03:13 INFO - 2015-10-23 14:03:13,916 DEBUG : BROWSER_OUTPUT:
14:03:15 INFO - 2015-10-23 14:03:15,132 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)
14:03:15 INFO - 2015-10-23 14:03:15,813 DEBUG : BROWSER_OUTPUT: RSS: Main: 293740544
14:03:15 INFO - 2015-10-23 14:03:15,813 DEBUG : BROWSER_OUTPUT:
14:03:17 INFO - 2015-10-23 14:03:17,017 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)
14:03:17 INFO - 2015-10-23 14:03:17,693 DEBUG : BROWSER_OUTPUT: RSS: Main: 294682624
14:03:17 INFO - 2015-10-23 14:03:17,694 DEBUG : BROWSER_OUTPUT:
14:03:18 INFO - 2015-10-23 14:03:18,920 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)
14:03:19 INFO - 2015-10-23 14:03:19,601 DEBUG : BROWSER_OUTPUT: RSS: Main: 294768640
14:03:19 INFO - 2015-10-23 14:03:19,601 DEBUG : BROWSER_OUTPUT:
14:03:20 INFO - 2015-10-23 14:03:20,831 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)
14:03:21 INFO - 2015-10-23 14:03:21,517 DEBUG : BROWSER_OUTPUT: RSS: Main: 293052416
14:03:21 INFO - 2015-10-23 14:03:21,517 DEBUG : BROWSER_OUTPUT:
14:03:22 INFO - 2015-10-23 14:03:22,741 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)
14:03:23 INFO - 2015-10-23 14:03:23,420 DEBUG : BROWSER_OUTPUT: RSS: Main: 292642816
14:03:23 INFO - 2015-10-23 14:03:23,420 DEBUG : BROWSER_OUTPUT:
14:03:24 INFO - 2015-10-23 14:03:24,647 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)
14:03:25 INFO - 2015-10-23 14:03:25,330 DEBUG : BROWSER_OUTPUT: RSS: Main: 293507072
14:03:25 INFO - 2015-10-23 14:03:25,330 DEBUG : BROWSER_OUTPUT:
14:03:26 INFO - 2015-10-23 14:03:26,518 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)
14:03:27 INFO - 2015-10-23 14:03:27,198 DEBUG : BROWSER_OUTPUT: RSS: Main: 295960576
14:03:27 INFO - 2015-10-23 14:03:27,199 DEBUG : BROWSER_OUTPUT:
14:03:28 INFO - 2015-10-23 14:03:28,423 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)
14:03:29 INFO - 2015-10-23 14:03:29,097 DEBUG : BROWSER_OUTPUT: RSS: Main: 295579648
14:03:29 INFO - 2015-10-23 14:03:29,097 DEBUG : BROWSER_OUTPUT:
14:03:30 INFO - 2015-10-23 14:03:30,324 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)
14:03:31 INFO - 2015-10-23 14:03:31,006 DEBUG : BROWSER_OUTPUT: RSS: Main: 296062976
14:03:31 INFO - 2015-10-23 14:03:31,006 DEBUG : BROWSER_OUTPUT:
14:03:31 INFO - 2015-10-23 14:03:31,775 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)
14:03:32 INFO - 2015-10-23 14:03:32,347 DEBUG : BROWSER_OUTPUT: RSS: Main: 288894976
14:03:32 INFO - 2015-10-23 14:03:32,348 DEBUG : BROWSER_OUTPUT:
14:03:33 INFO - 2015-10-23 14:03:33,043 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)
14:03:33 INFO - 2015-10-23 14:03:33,627 DEBUG : BROWSER_OUTPUT: RSS: Main: 300789760
14:03:33 INFO - 2015-10-23 14:03:33,628 DEBUG : BROWSER_OUTPUT:
14:03:33 INFO - 2015-10-23 14:03:33,945 DEBUG : BROWSER_OUTPUT: 1445634213944 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]
14:03:34 INFO - 2015-10-23 14:03:34,345 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)
14:03:34 INFO - 2015-10-23 14:03:34,947 DEBUG : BROWSER_OUTPUT: RSS: Main: 305582080
14:03:34 INFO - 2015-10-23 14:03:34,947 DEBUG : BROWSER_OUTPUT:
14:03:35 INFO - 2015-10-23 14:03:35,651 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)
14:03:36 INFO - 2015-10-23 14:03:36,243 DEBUG : BROWSER_OUTPUT: RSS: Main: 305176576
14:03:36 INFO - 2015-10-23 14:03:36,243 DEBUG : BROWSER_OUTPUT:
14:03:36 INFO - 2015-10-23 14:03:36,950 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)
14:03:37 INFO - 2015-10-23 14:03:37,549 DEBUG : BROWSER_OUTPUT: RSS: Main: 305651712
14:03:37 INFO - 2015-10-23 14:03:37,549 DEBUG : BROWSER_OUTPUT:
14:03:38 INFO - 2015-10-23 14:03:38,252 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)
14:03:38 INFO - 2015-10-23 14:03:38,845 DEBUG : BROWSER_OUTPUT: RSS: Main: 304496640
14:03:38 INFO - 2015-10-23 14:03:38,845 DEBUG : BROWSER_OUTPUT:
14:03:39 INFO - 2015-10-23 14:03:39,550 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)
14:03:40 INFO - 2015-10-23 14:03:40,148 DEBUG : BROWSER_OUTPUT: RSS: Main: 305360896
14:03:40 INFO - 2015-10-23 14:03:40,148 DEBUG : BROWSER_OUTPUT:
14:03:40 INFO - 2015-10-23 14:03:40,849 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)
14:03:41 INFO - 2015-10-23 14:03:41,452 DEBUG : BROWSER_OUTPUT: RSS: Main: 305520640
14:03:41 INFO - 2015-10-23 14:03:41,452 DEBUG : BROWSER_OUTPUT:
14:03:42 INFO - 2015-10-23 14:03:42,153 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)
14:03:42 INFO - 2015-10-23 14:03:42,746 DEBUG : BROWSER_OUTPUT: RSS: Main: 304451584
14:03:42 INFO - 2015-10-23 14:03:42,746 DEBUG : BROWSER_OUTPUT:
14:03:43 INFO - 2015-10-23 14:03:43,449 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)
14:03:44 INFO - 2015-10-23 14:03:44,040 DEBUG : BROWSER_OUTPUT: RSS: Main: 305033216
14:03:44 INFO - 2015-10-23 14:03:44,040 DEBUG : BROWSER_OUTPUT:
14:03:44 INFO - 2015-10-23 14:03:44,747 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)
14:03:45 INFO - 2015-10-23 14:03:45,339 DEBUG : BROWSER_OUTPUT: RSS: Main: 300081152
14:03:45 INFO - 2015-10-23 14:03:45,339 DEBUG : BROWSER_OUTPUT:
14:03:46 INFO - 2015-10-23 14:03:46,049 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)
14:03:46 INFO - 2015-10-23 14:03:46,650 DEBUG : BROWSER_OUTPUT: RSS: Main: 299024384
14:03:46 INFO - 2015-10-23 14:03:46,650 DEBUG : BROWSER_OUTPUT:
14:03:47 INFO - 2015-10-23 14:03:47,354 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)
14:03:47 INFO - 2015-10-23 14:03:47,945 DEBUG : BROWSER_OUTPUT: RSS: Main: 298946560
14:03:47 INFO - 2015-10-23 14:03:47,945 DEBUG : BROWSER_OUTPUT:
14:03:48 INFO - 2015-10-23 14:03:48,650 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)
14:03:49 INFO - 2015-10-23 14:03:49,242 DEBUG : BROWSER_OUTPUT: RSS: Main: 299048960
14:03:49 INFO - 2015-10-23 14:03:49,242 DEBUG : BROWSER_OUTPUT:
14:03:49 INFO - 2015-10-23 14:03:49,949 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)
14:03:50 INFO - 2015-10-23 14:03:50,548 DEBUG : BROWSER_OUTPUT: RSS: Main: 299081728
14:03:50 INFO - 2015-10-23 14:03:50,548 DEBUG : BROWSER_OUTPUT:
14:03:51 INFO - 2015-10-23 14:03:51,253 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)
14:03:51 INFO - 2015-10-23 14:03:51,845 DEBUG : BROWSER_OUTPUT: RSS: Main: 299163648
14:03:51 INFO - 2015-10-23 14:03:51,845 DEBUG : BROWSER_OUTPUT:
14:03:52 INFO - 2015-10-23 14:03:52,555 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)
14:03:53 INFO - 2015-10-23 14:03:53,156 DEBUG : BROWSER_OUTPUT: RSS: Main: 299122688
14:03:53 INFO - 2015-10-23 14:03:53,156 DEBUG : BROWSER_OUTPUT:
14:03:53 INFO - 2015-10-23 14:03:53,829 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)
14:03:54 INFO - 2015-10-23 14:03:54,424 DEBUG : BROWSER_OUTPUT: RSS: Main: 299151360
14:03:54 INFO - 2015-10-23 14:03:54,424 DEBUG : BROWSER_OUTPUT:
14:03:55 INFO - 2015-10-23 14:03:55,099 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)
14:03:55 INFO - 2015-10-23 14:03:55,694 DEBUG : BROWSER_OUTPUT: RSS: Main: 297590784
14:03:55 INFO - 2015-10-23 14:03:55,695 DEBUG : BROWSER_OUTPUT:
14:03:56 INFO - 2015-10-23 14:03:56,401 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)
14:03:56 INFO - 2015-10-23 14:03:56,993 DEBUG : BROWSER_OUTPUT: RSS: Main: 296464384
14:03:56 INFO - 2015-10-23 14:03:56,994 DEBUG : BROWSER_OUTPUT:
14:03:57 INFO - 2015-10-23 14:03:57,716 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)
14:03:58 INFO - 2015-10-23 14:03:58,317 DEBUG : BROWSER_OUTPUT: RSS: Main: 296509440
14:03:58 INFO - 2015-10-23 14:03:58,318 DEBUG : BROWSER_OUTPUT:
14:03:59 INFO - 2015-10-23 14:03:59,017 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)
14:03:59 INFO - 2015-10-23 14:03:59,612 DEBUG : BROWSER_OUTPUT: RSS: Main: 296869888
14:03:59 INFO - 2015-10-23 14:03:59,612 DEBUG : BROWSER_OUTPUT:
14:04:00 INFO - 2015-10-23 14:04:00,319 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)
14:04:00 INFO - 2015-10-23 14:04:00,910 DEBUG : BROWSER_OUTPUT: RSS: Main: 296693760
14:04:00 INFO - 2015-10-23 14:04:00,910 DEBUG : BROWSER_OUTPUT:
14:04:01 INFO - 2015-10-23 14:04:01,618 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)
14:04:02 INFO - 2015-10-23 14:04:02,210 DEBUG : BROWSER_OUTPUT: RSS: Main: 296701952
14:04:02 INFO - 2015-10-23 14:04:02,210 DEBUG : BROWSER_OUTPUT:
14:04:02 INFO - 2015-10-23 14:04:02,917 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)
14:04:03 INFO - 2015-10-23 14:04:03,167 DEBUG : BROWSER_OUTPUT: RSS: Main: 301113344
14:04:03 INFO - 2015-10-23 14:04:03,167 DEBUG : BROWSER_OUTPUT:
14:04:03 INFO - 2015-10-23 14:04:03,167 DEBUG : BROWSER_OUTPUT: __start_tp_report
14:04:03 INFO - 2015-10-23 14:04:03,167 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load
14:04:03 INFO - 2015-10-23 14:04:03,167 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load_details
14:04:03 INFO - 2015-10-23 14:04:03,168 DEBUG : BROWSER_OUTPUT: |i|pagename|runs|
14:04:03 INFO - 2015-10-23 14:04:03,168 DEBUG : BROWSER_OUTPUT: |0;dhtml.html;1109;1141;1059;1146;1144;1145;1142;1147;1181;1147;1155;1153;1063;1183;1062;1184;1156;1143;1148;1161;1149;1150;1143;1153;1155
14:04:03 INFO - 2015-10-23 14:04:03,169 DEBUG : BROWSER_OUTPUT: |1;tablemutation.html;264;262;267;258;259;260;258;259;259;257;258;259;260;259;259;259;261;261;259;259;260;259;260;259;258
14:04:03 INFO - 2015-10-23 14:04:03,169 DEBUG : BROWSER_OUTPUT: __end_tp_report
14:04:03 INFO - 2015-10-23 14:04:03,169 DEBUG : BROWSER_OUTPUT: __start_cc_report
14:04:03 INFO - 2015-10-23 14:04:03,169 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_cycle_collect,6444
14:04:03 INFO - 2015-10-23 14:04:03,170 DEBUG : BROWSER_OUTPUT: __end_cc_report
14:04:03 INFO - 2015-10-23 14:04:03,170 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634243166__endTimestamp
14:04:03 INFO - 2015-10-23 14:04:03,170 DEBUG : BROWSER_OUTPUT:
14:04:03 INFO - 2015-10-23 14:04:03,170 DEBUG : BROWSER_OUTPUT: ------- Summary: start -------
14:04:03 INFO - 2015-10-23 14:04:03,170 DEBUG : BROWSER_OUTPUT: Number of tests: 2
14:04:03 INFO - 2015-10-23 14:04:03,170 DEBUG : BROWSER_OUTPUT:
14:04:03 INFO - 2015-10-23 14:04:03,170 DEBUG : BROWSER_OUTPUT: [#0] dhtml.html Cycles:25 Average:1140.76 Median:1147.00 stddev:33.49 (2.9%) stddev-sans-first:33.53
14:04:03 INFO - 2015-10-23 14:04:03,170 DEBUG : BROWSER_OUTPUT: Values: 1109.0 1141.0 1059.0 1146.0 1144.0 1145.0 1142.0 1147.0 1181.0 1147.0 1155.0 1153.0 1063.0 1183.0 1062.0 1184.0 1156.0 1143.0 1148.0 1161.0 1149.0 1150.0 1143.0 1153.0 1155.0
14:04:03 INFO - 2015-10-23 14:04:03,171 DEBUG : BROWSER_OUTPUT:
14:04:03 INFO - 2015-10-23 14:04:03,171 DEBUG : BROWSER_OUTPUT: [#1] tablemutation.html Cycles:25 Average:259.72 Median:259.00 stddev:2.09 (0.8%) stddev-sans-first:1.93
14:04:03 INFO - 2015-10-23 14:04:03,171 DEBUG : BROWSER_OUTPUT: Values: 264.0 262.0 267.0 258.0 259.0 260.0 258.0 259.0 259.0 257.0 258.0 259.0 260.0 259.0 259.0 259.0 261.0 261.0 259.0 259.0 260.0 259.0 260.0 259.0 258.0
14:04:03 INFO - 2015-10-23 14:04:03,171 DEBUG : BROWSER_OUTPUT: -------- Summary: end --------
14:04:03 INFO - 2015-10-23 14:04:03,171 DEBUG : BROWSER_OUTPUT:
14:04:03 INFO - 2015-10-23 14:04:03,677 INFO : Browser exited with error code: 0
14:04:03 INFO - 2015-10-23 14:04:03,698 INFO : Completed test a11yr (00:01:35)
14:04:03 INFO - 2015-10-23 14:04:03,698 INFO : Starting test ts_paint
14:04:03 INFO - 2015-10-23 14:04:03,698 DEBUG : operating with platform_type : mac_
14:04:03 INFO - 2015-10-23 14:04:03,698 INFO : Initialising browser for ts_paint test...
14:04:03 INFO - 2015-10-23 14:04:03,712 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpigpEZu/profile http://localhost:49269/getInfo.html
14:04:05 INFO - 2015-10-23 14:04:05,880 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
14:04:05 INFO - 2015-10-23 14:04:05,880 DEBUG : BROWSER_OUTPUT: colorDepth:24
14:04:05 INFO - 2015-10-23 14:04:05,880 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/689
14:04:05 INFO - 2015-10-23 14:04:05,881 DEBUG : BROWSER_OUTPUT: __metrics
14:04:05 INFO - 2015-10-23 14:04:05,888 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]
14:04:06 INFO - 2015-10-23 14:04:06,160 DEBUG : BROWSER_OUTPUT: console.error:
14:04:06 INFO - 2015-10-23 14:04:06,160 DEBUG : BROWSER_OUTPUT: Message: [Exception... "Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [mozIStorageAsyncStatement.executeAsync]" nsresult: "0x80040111 (NS_ERROR_NOT_AVAILABLE)" location: "JS frame :: resource://gre/modules/Sqlite.jsm :: ConnectionData.prototype<._executeStatement :: line 758" data: no]
14:04:06 INFO - 2015-10-23 14:04:06,160 DEBUG : BROWSER_OUTPUT: Stack:
14:04:06 INFO - 2015-10-23 14:04:06,160 DEBUG : BROWSER_OUTPUT: ConnectionData.prototype<._executeStatement@resource://gre/modules/Sqlite.jsm:758:19
14:04:06 INFO - 2015-10-23 14:04:06,160 DEBUG : BROWSER_OUTPUT: ConnectionData.prototype<.executeCached/<@resource://gre/modules/Sqlite.jsm:493:9
14:04:06 INFO - 2015-10-23 14:04:06,161 DEBUG : BROWSER_OUTPUT: ConnectionData.prototype<.executeCached@resource://gre/modules/Sqlite.jsm:491:1
14:04:06 INFO - 2015-10-23 14:04:06,161 DEBUG : BROWSER_OUTPUT: ConnectionData.prototype<.executeBeforeShutdown/loggedDb<.executeCached.value<@resource://gre/modules/Sqlite.jsm:368:51
14:04:06 INFO - 2015-10-23 14:04:06,161 DEBUG : BROWSER_OUTPUT: TaskImpl_run@resource://gre/modules/Task.jsm:314:40
14:04:06 INFO - 2015-10-23 14:04:06,161 DEBUG : BROWSER_OUTPUT: TaskImpl@resource://gre/modules/Task.jsm:275:3
14:04:06 INFO - 2015-10-23 14:04:06,161 DEBUG : BROWSER_OUTPUT: createAsyncFunction/asyncFunction@resource://gre/modules/Task.jsm:249:14
14:04:06 INFO - 2015-10-23 14:04:06,161 DEBUG : BROWSER_OUTPUT: setAncestorsLastModified<@resource://gre/modules/Bookmarks.jsm:1347:9
14:04:06 INFO - 2015-10-23 14:04:06,161 DEBUG : BROWSER_OUTPUT: TaskImpl_run@resource://gre/modules/Task.jsm:314:40
14:04:06 INFO - 2015-10-23 14:04:06,161 DEBUG : BROWSER_OUTPUT: TaskImpl@resource://gre/modules/Task.jsm:275:3
14:04:06 INFO - 2015-10-23 14:04:06,161 DEBUG : BROWSER_OUTPUT: createAsyncFunction/asyncFunction@resource://gre/modules/Task.jsm:249:14
14:04:06 INFO - 2015-10-23 14:04:06,161 DEBUG : BROWSER_OUTPUT: transaction@resource://gre/modules/Bookmarks.jsm:808:13
14:04:06 INFO - 2015-10-23 14:04:06,161 DEBUG : BROWSER_OUTPUT: TaskImpl_run@resource://gre/modules/Task.jsm:314:40
14:04:06 INFO - 2015-10-23 14:04:06,161 DEBUG : BROWSER_OUTPUT: Handler.prototype.process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:934:23
14:04:06 INFO - 2015-10-23 14:04:06,162 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:813:7
14:04:06 INFO - 2015-10-23 14:04:06,162 DEBUG : BROWSER_OUTPUT: Promise*this.PromiseWalker.scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:744:11
14:04:06 INFO - 2015-10-23 14:04:06,162 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:776:7
14:04:06 INFO - 2015-10-23 14:04:06,162 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:711:7
14:04:06 INFO - 2015-10-23 14:04:06,162 DEBUG : BROWSER_OUTPUT: TaskImpl_run@resource://gre/modules/Task.jsm:319:13
14:04:06 INFO - 2015-10-23 14:04:06,162 DEBUG : BROWSER_OUTPUT: Spinner.prototype.observe@resource://gre/modules/AsyncShutdown.jsm:523:9
14:04:06 INFO - 2015-10-23 14:04:06,162 DEBUG : BROWSER_OUTPUT:
14:04:06 INFO - 2015-10-23 14:04:06,607 INFO : Browser initialized.
14:04:06 INFO - 2015-10-23 14:04:06,608 INFO : Running cycle 1/20 for ts_paint test...
14:04:06 INFO - 2015-10-23 14:04:06,608 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpigpEZu/profile http://localhost:49269/startup_test/tspaint_test.html
14:04:08 INFO - 2015-10-23 14:04:08,330 DEBUG : BROWSER_OUTPUT: __start_report1714__end_report
14:04:08 INFO - 2015-10-23 14:04:08,330 DEBUG : BROWSER_OUTPUT:
14:04:08 INFO - 2015-10-23 14:04:08,347 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634248338__endTimestamp
14:04:08 INFO - 2015-10-23 14:04:08,960 INFO : Browser exited with error code: 0
14:04:08 INFO - 2015-10-23 14:04:08,962 INFO : Running cycle 2/20 for ts_paint test...
14:04:08 INFO - 2015-10-23 14:04:08,962 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpigpEZu/profile http://localhost:49269/startup_test/tspaint_test.html
14:04:10 INFO - 2015-10-23 14:04:10,232 DEBUG : BROWSER_OUTPUT: __start_report1264__end_report
14:04:10 INFO - 2015-10-23 14:04:10,232 DEBUG : BROWSER_OUTPUT:
14:04:10 INFO - 2015-10-23 14:04:10,232 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634250230__endTimestamp
14:04:10 INFO - 2015-10-23 14:04:10,852 INFO : Browser exited with error code: 0
14:04:10 INFO - 2015-10-23 14:04:10,853 INFO : Running cycle 3/20 for ts_paint test...
14:04:10 INFO - 2015-10-23 14:04:10,854 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpigpEZu/profile http://localhost:49269/startup_test/tspaint_test.html
14:04:12 INFO - 2015-10-23 14:04:12,132 DEBUG : BROWSER_OUTPUT: __start_report1270__end_report
14:04:12 INFO - 2015-10-23 14:04:12,132 DEBUG : BROWSER_OUTPUT:
14:04:12 INFO - 2015-10-23 14:04:12,149 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634252142__endTimestamp
14:04:12 INFO - 2015-10-23 14:04:12,818 INFO : Browser exited with error code: 0
14:04:12 INFO - 2015-10-23 14:04:12,819 INFO : Running cycle 4/20 for ts_paint test...
14:04:12 INFO - 2015-10-23 14:04:12,819 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpigpEZu/profile http://localhost:49269/startup_test/tspaint_test.html
14:04:14 INFO - 2015-10-23 14:04:14,083 DEBUG : BROWSER_OUTPUT: __start_report1260__end_report
14:04:14 INFO - 2015-10-23 14:04:14,083 DEBUG : BROWSER_OUTPUT:
14:04:14 INFO - 2015-10-23 14:04:14,099 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634254096__endTimestamp
14:04:14 INFO - 2015-10-23 14:04:14,817 INFO : Browser exited with error code: 0
14:04:14 INFO - 2015-10-23 14:04:14,818 INFO : Running cycle 5/20 for ts_paint test...
14:04:14 INFO - 2015-10-23 14:04:14,819 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpigpEZu/profile http://localhost:49269/startup_test/tspaint_test.html
14:04:16 INFO - 2015-10-23 14:04:16,082 DEBUG : BROWSER_OUTPUT: __start_report1261__end_report
14:04:16 INFO - 2015-10-23 14:04:16,083 DEBUG : BROWSER_OUTPUT:
14:04:16 INFO - 2015-10-23 14:04:16,100 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634256096__endTimestamp
14:04:16 INFO - 2015-10-23 14:04:16,858 INFO : Browser exited with error code: 0
14:04:16 INFO - 2015-10-23 14:04:16,860 INFO : Running cycle 6/20 for ts_paint test...
14:04:16 INFO - 2015-10-23 14:04:16,860 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpigpEZu/profile http://localhost:49269/startup_test/tspaint_test.html
14:04:18 INFO - 2015-10-23 14:04:18,129 DEBUG : BROWSER_OUTPUT: __start_report1267__end_report
14:04:18 INFO - 2015-10-23 14:04:18,129 DEBUG : BROWSER_OUTPUT:
14:04:18 INFO - 2015-10-23 14:04:18,133 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634258132__endTimestamp
14:04:18 INFO - 2015-10-23 14:04:18,859 INFO : Browser exited with error code: 0
14:04:18 INFO - 2015-10-23 14:04:18,861 INFO : Running cycle 7/20 for ts_paint test...
14:04:18 INFO - 2015-10-23 14:04:18,861 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpigpEZu/profile http://localhost:49269/startup_test/tspaint_test.html
14:04:20 INFO - 2015-10-23 14:04:20,135 DEBUG : BROWSER_OUTPUT: __start_report1270__end_report
14:04:20 INFO - 2015-10-23 14:04:20,135 DEBUG : BROWSER_OUTPUT:
14:04:20 INFO - 2015-10-23 14:04:20,143 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634260142__endTimestamp
14:04:20 INFO - 2015-10-23 14:04:20,890 INFO : Browser exited with error code: 0
14:04:20 INFO - 2015-10-23 14:04:20,891 INFO : Running cycle 8/20 for ts_paint test...
14:04:20 INFO - 2015-10-23 14:04:20,891 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpigpEZu/profile http://localhost:49269/startup_test/tspaint_test.html
14:04:22 INFO - 2015-10-23 14:04:22,151 DEBUG : BROWSER_OUTPUT: __start_report1255__end_report
14:04:22 INFO - 2015-10-23 14:04:22,151 DEBUG : BROWSER_OUTPUT:
14:04:22 INFO - 2015-10-23 14:04:22,169 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634262162__endTimestamp
14:04:22 INFO - 2015-10-23 14:04:22,915 INFO : Browser exited with error code: 0
14:04:22 INFO - 2015-10-23 14:04:22,916 INFO : Running cycle 9/20 for ts_paint test...
14:04:22 INFO - 2015-10-23 14:04:22,916 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpigpEZu/profile http://localhost:49269/startup_test/tspaint_test.html
14:04:24 INFO - 2015-10-23 14:04:24,185 DEBUG : BROWSER_OUTPUT: __start_report1264__end_report
14:04:24 INFO - 2015-10-23 14:04:24,185 DEBUG : BROWSER_OUTPUT:
14:04:24 INFO - 2015-10-23 14:04:24,201 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634264196__endTimestamp
14:04:24 INFO - 2015-10-23 14:04:24,931 INFO : Browser exited with error code: 0
14:04:24 INFO - 2015-10-23 14:04:24,932 INFO : Running cycle 10/20 for ts_paint test...
14:04:24 INFO - 2015-10-23 14:04:24,932 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpigpEZu/profile http://localhost:49269/startup_test/tspaint_test.html
14:04:26 INFO - 2015-10-23 14:04:26,199 DEBUG : BROWSER_OUTPUT: __start_report1264__end_report
14:04:26 INFO - 2015-10-23 14:04:26,199 DEBUG : BROWSER_OUTPUT:
14:04:26 INFO - 2015-10-23 14:04:26,214 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634266212__endTimestamp
14:04:26 INFO - 2015-10-23 14:04:26,951 INFO : Browser exited with error code: 0
14:04:26 INFO - 2015-10-23 14:04:26,952 INFO : Running cycle 11/20 for ts_paint test...
14:04:26 INFO - 2015-10-23 14:04:26,952 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpigpEZu/profile http://localhost:49269/startup_test/tspaint_test.html
14:04:28 INFO - 2015-10-23 14:04:28,243 DEBUG : BROWSER_OUTPUT: __start_report1288__end_report
14:04:28 INFO - 2015-10-23 14:04:28,244 DEBUG : BROWSER_OUTPUT:
14:04:28 INFO - 2015-10-23 14:04:28,259 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634268256__endTimestamp
14:04:28 INFO - 2015-10-23 14:04:28,987 INFO : Browser exited with error code: 0
14:04:28 INFO - 2015-10-23 14:04:28,988 INFO : Running cycle 12/20 for ts_paint test...
14:04:28 INFO - 2015-10-23 14:04:28,988 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpigpEZu/profile http://localhost:49269/startup_test/tspaint_test.html
14:04:30 INFO - 2015-10-23 14:04:30,267 DEBUG : BROWSER_OUTPUT: __start_report1269__end_report
14:04:30 INFO - 2015-10-23 14:04:30,267 DEBUG : BROWSER_OUTPUT:
14:04:30 INFO - 2015-10-23 14:04:30,276 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634270273__endTimestamp
14:04:31 INFO - 2015-10-23 14:04:31,032 INFO : Browser exited with error code: 0
14:04:31 INFO - 2015-10-23 14:04:31,034 INFO : Running cycle 13/20 for ts_paint test...
14:04:31 INFO - 2015-10-23 14:04:31,034 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpigpEZu/profile http://localhost:49269/startup_test/tspaint_test.html
14:04:32 INFO - 2015-10-23 14:04:32,299 DEBUG : BROWSER_OUTPUT: __start_report1261__end_report
14:04:32 INFO - 2015-10-23 14:04:32,300 DEBUG : BROWSER_OUTPUT:
14:04:32 INFO - 2015-10-23 14:04:32,315 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634272312__endTimestamp
14:04:33 INFO - 2015-10-23 14:04:33,069 INFO : Browser exited with error code: 0
14:04:33 INFO - 2015-10-23 14:04:33,070 INFO : Running cycle 14/20 for ts_paint test...
14:04:33 INFO - 2015-10-23 14:04:33,070 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpigpEZu/profile http://localhost:49269/startup_test/tspaint_test.html
14:04:34 INFO - 2015-10-23 14:04:34,364 DEBUG : BROWSER_OUTPUT: __start_report1291__end_report
14:04:34 INFO - 2015-10-23 14:04:34,365 DEBUG : BROWSER_OUTPUT:
14:04:34 INFO - 2015-10-23 14:04:34,373 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634274370__endTimestamp
14:04:35 INFO - 2015-10-23 14:04:35,091 INFO : Browser exited with error code: 0
14:04:35 INFO - 2015-10-23 14:04:35,093 INFO : Running cycle 15/20 for ts_paint test...
14:04:35 INFO - 2015-10-23 14:04:35,093 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpigpEZu/profile http://localhost:49269/startup_test/tspaint_test.html
14:04:36 INFO - 2015-10-23 14:04:36,372 DEBUG : BROWSER_OUTPUT: __start_report1271__end_report
14:04:36 INFO - 2015-10-23 14:04:36,372 DEBUG : BROWSER_OUTPUT:
14:04:36 INFO - 2015-10-23 14:04:36,381 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634276380__endTimestamp
14:04:37 INFO - 2015-10-23 14:04:37,136 INFO : Browser exited with error code: 0
14:04:37 INFO - 2015-10-23 14:04:37,137 INFO : Running cycle 16/20 for ts_paint test...
14:04:37 INFO - 2015-10-23 14:04:37,137 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpigpEZu/profile http://localhost:49269/startup_test/tspaint_test.html
14:04:38 INFO - 2015-10-23 14:04:38,430 DEBUG : BROWSER_OUTPUT: __start_report1291__end_report
14:04:38 INFO - 2015-10-23 14:04:38,431 DEBUG : BROWSER_OUTPUT:
14:04:38 INFO - 2015-10-23 14:04:38,438 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634278437__endTimestamp
14:04:39 INFO - 2015-10-23 14:04:39,180 INFO : Browser exited with error code: 0
14:04:39 INFO - 2015-10-23 14:04:39,181 INFO : Running cycle 17/20 for ts_paint test...
14:04:39 INFO - 2015-10-23 14:04:39,181 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpigpEZu/profile http://localhost:49269/startup_test/tspaint_test.html
14:04:40 INFO - 2015-10-23 14:04:40,452 DEBUG : BROWSER_OUTPUT: __start_report1266__end_report
14:04:40 INFO - 2015-10-23 14:04:40,452 DEBUG : BROWSER_OUTPUT:
14:04:40 INFO - 2015-10-23 14:04:40,468 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634280463__endTimestamp
14:04:41 INFO - 2015-10-23 14:04:41,220 INFO : Browser exited with error code: 0
14:04:41 INFO - 2015-10-23 14:04:41,221 INFO : Running cycle 18/20 for ts_paint test...
14:04:41 INFO - 2015-10-23 14:04:41,221 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpigpEZu/profile http://localhost:49269/startup_test/tspaint_test.html
14:04:42 INFO - 2015-10-23 14:04:42,483 DEBUG : BROWSER_OUTPUT: __start_report1260__end_report
14:04:42 INFO - 2015-10-23 14:04:42,483 DEBUG : BROWSER_OUTPUT:
14:04:42 INFO - 2015-10-23 14:04:42,499 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634282496__endTimestamp
14:04:43 INFO - 2015-10-23 14:04:43,276 INFO : Browser exited with error code: 0
14:04:43 INFO - 2015-10-23 14:04:43,278 INFO : Running cycle 19/20 for ts_paint test...
14:04:43 INFO - 2015-10-23 14:04:43,278 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpigpEZu/profile http://localhost:49269/startup_test/tspaint_test.html
14:04:44 INFO - 2015-10-23 14:04:44,551 DEBUG : BROWSER_OUTPUT: __start_report1269__end_report
14:04:44 INFO - 2015-10-23 14:04:44,551 DEBUG : BROWSER_OUTPUT:
14:04:44 INFO - 2015-10-23 14:04:44,568 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634284563__endTimestamp
14:04:45 INFO - 2015-10-23 14:04:45,373 INFO : Browser exited with error code: 0
14:04:45 INFO - 2015-10-23 14:04:45,374 INFO : Running cycle 20/20 for ts_paint test...
14:04:45 INFO - 2015-10-23 14:04:45,374 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpigpEZu/profile http://localhost:49269/startup_test/tspaint_test.html
14:04:46 INFO - 2015-10-23 14:04:46,646 DEBUG : BROWSER_OUTPUT: __start_report1266__end_report
14:04:46 INFO - 2015-10-23 14:04:46,646 DEBUG : BROWSER_OUTPUT:
14:04:46 INFO - 2015-10-23 14:04:46,661 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634286656__endTimestamp
14:04:47 INFO - 2015-10-23 14:04:47,419 INFO : Browser exited with error code: 0
14:04:47 INFO - 2015-10-23 14:04:47,446 INFO : Completed test ts_paint (00:00:43)
14:04:47 INFO - 2015-10-23 14:04:47,446 INFO : Starting test tpaint
14:04:47 INFO - 2015-10-23 14:04:47,446 DEBUG : operating with platform_type : mac_
14:04:47 INFO - 2015-10-23 14:04:47,447 INFO : Initialising browser for tpaint test...
14:04:47 INFO - 2015-10-23 14:04:47,462 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp9R_cob/profile http://localhost:49269/getInfo.html
14:04:49 INFO - 2015-10-23 14:04:49,624 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
14:04:49 INFO - 2015-10-23 14:04:49,624 DEBUG : BROWSER_OUTPUT: colorDepth:24
14:04:49 INFO - 2015-10-23 14:04:49,626 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/689
14:04:49 INFO - 2015-10-23 14:04:49,626 DEBUG : BROWSER_OUTPUT: __metrics
14:04:49 INFO - 2015-10-23 14:04:49,642 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]
14:04:50 INFO - 2015-10-23 14:04:50,375 INFO : Browser initialized.
14:04:50 INFO - 2015-10-23 14:04:50,376 INFO : Running cycle 1/1 for tpaint test...
14:04:50 INFO - 2015-10-23 14:04:50,376 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmp9R_cob/profile file:///builds/slave/test/build/tests/talos/talos/startup_test/tpaint.html?auto=1
14:05:19 INFO - 2015-10-23 14:05:19,192 DEBUG : BROWSER_OUTPUT: __start_report308.40499999999975|312.60000000000036|314.58500000000004|316.6750000000002|317.3250000000007|319.28500000000076|324.3050000000003|324.4150000000009|326.16499999999905|326.72000000000116|327.2449999999999|332.02999999999884|333.6350000000002|339.375|342.7099999999991|345.5099999999984|359.58500000000276|404.65500000000065|405.5300000000025|505.35000000000036__end_report__startTimestamp1445634319190__endTimestamp
14:05:19 INFO - 2015-10-23 14:05:19,192 DEBUG : BROWSER_OUTPUT: openingTimes=312.60000000000036,314.58500000000004,316.6750000000002,317.3250000000007,319.28500000000076,324.3050000000003,324.4150000000009,326.16499999999905,326.72000000000116,327.2449999999999,332.02999999999884,333.6350000000002,339.375,342.7099999999991,345.5099999999984,359.58500000000276,404.65500000000065,405.5300000000025,505.35000000000036
14:05:19 INFO - 2015-10-23 14:05:19,192 DEBUG : BROWSER_OUTPUT: avgOpenTime:344.31
14:05:19 INFO - 2015-10-23 14:05:19,192 DEBUG : BROWSER_OUTPUT: minOpenTime:308.40
14:05:19 INFO - 2015-10-23 14:05:19,192 DEBUG : BROWSER_OUTPUT: maxOpenTime:505.35
14:05:19 INFO - 2015-10-23 14:05:19,192 DEBUG : BROWSER_OUTPUT: medOpenTime:326.9825000000005
14:05:19 INFO - 2015-10-23 14:05:19,192 DEBUG : BROWSER_OUTPUT: __xulWinOpenTime:326.9825000000005
14:05:19 INFO - 2015-10-23 14:05:19,929 INFO : Browser exited with error code: 0
14:05:19 INFO - 2015-10-23 14:05:19,947 INFO : Completed test tpaint (00:00:32)
14:05:19 INFO - 2015-10-23 14:05:19,947 INFO : Starting test sessionrestore
14:05:19 INFO - 2015-10-23 14:05:19,948 DEBUG : operating with platform_type : mac_
14:05:19 INFO - 2015-10-23 14:05:19,948 INFO : Initialising browser for sessionrestore test...
14:05:19 INFO - 2015-10-23 14:05:19,966 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile http://localhost:49269/getInfo.html
14:05:25 INFO - 2015-10-23 14:05:25,321 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
14:05:25 INFO - 2015-10-23 14:05:25,321 DEBUG : BROWSER_OUTPUT: colorDepth:24
14:05:25 INFO - 2015-10-23 14:05:25,322 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1200/743
14:05:25 INFO - 2015-10-23 14:05:25,322 DEBUG : BROWSER_OUTPUT: __metrics
14:05:25 INFO - 2015-10-23 14:05:25,407 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]
14:05:26 INFO - 2015-10-23 14:05:26,156 DEBUG : BROWSER_OUTPUT: console.error:
14:05:26 INFO - 2015-10-23 14:05:26,157 DEBUG : BROWSER_OUTPUT: Message: [Exception... "Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [mozIStorageAsyncStatement.executeAsync]" nsresult: "0x80040111 (NS_ERROR_NOT_AVAILABLE)" location: "JS frame :: resource://gre/modules/Sqlite.jsm :: ConnectionData.prototype<._executeStatement :: line 758" data: no]
14:05:26 INFO - 2015-10-23 14:05:26,157 DEBUG : BROWSER_OUTPUT: Stack:
14:05:26 INFO - 2015-10-23 14:05:26,158 DEBUG : BROWSER_OUTPUT: ConnectionData.prototype<._executeStatement@resource://gre/modules/Sqlite.jsm:758:19
14:05:26 INFO - 2015-10-23 14:05:26,158 DEBUG : BROWSER_OUTPUT: ConnectionData.prototype<.executeCached/<@resource://gre/modules/Sqlite.jsm:493:9
14:05:26 INFO - 2015-10-23 14:05:26,158 DEBUG : BROWSER_OUTPUT: ConnectionData.prototype<.executeCached@resource://gre/modules/Sqlite.jsm:491:1
14:05:26 INFO - 2015-10-23 14:05:26,158 DEBUG : BROWSER_OUTPUT: ConnectionData.prototype<.executeBeforeShutdown/loggedDb<.executeCached.value<@resource://gre/modules/Sqlite.jsm:368:51
14:05:26 INFO - 2015-10-23 14:05:26,158 DEBUG : BROWSER_OUTPUT: TaskImpl_run@resource://gre/modules/Task.jsm:314:40
14:05:26 INFO - 2015-10-23 14:05:26,158 DEBUG : BROWSER_OUTPUT: TaskImpl@resource://gre/modules/Task.jsm:275:3
14:05:26 INFO - 2015-10-23 14:05:26,158 DEBUG : BROWSER_OUTPUT: createAsyncFunction/asyncFunction@resource://gre/modules/Task.jsm:249:14
14:05:26 INFO - 2015-10-23 14:05:26,159 DEBUG : BROWSER_OUTPUT: setAncestorsLastModified<@resource://gre/modules/Bookmarks.jsm:1347:9
14:05:26 INFO - 2015-10-23 14:05:26,159 DEBUG : BROWSER_OUTPUT: TaskImpl_run@resource://gre/modules/Task.jsm:314:40
14:05:26 INFO - 2015-10-23 14:05:26,159 DEBUG : BROWSER_OUTPUT: TaskImpl@resource://gre/modules/Task.jsm:275:3
14:05:26 INFO - 2015-10-23 14:05:26,159 DEBUG : BROWSER_OUTPUT: createAsyncFunction/asyncFunction@resource://gre/modules/Task.jsm:249:14
14:05:26 INFO - 2015-10-23 14:05:26,159 DEBUG : BROWSER_OUTPUT: transaction@resource://gre/modules/Bookmarks.jsm:808:13
14:05:26 INFO - 2015-10-23 14:05:26,159 DEBUG : BROWSER_OUTPUT: TaskImpl_run@resource://gre/modules/Task.jsm:314:40
14:05:26 INFO - 2015-10-23 14:05:26,161 DEBUG : BROWSER_OUTPUT: Handler.prototype.process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:934:23
14:05:26 INFO - 2015-10-23 14:05:26,161 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:813:7
14:05:26 INFO - 2015-10-23 14:05:26,161 DEBUG : BROWSER_OUTPUT: Promise*this.PromiseWalker.scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:744:11
14:05:26 INFO - 2015-10-23 14:05:26,161 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:776:7
14:05:26 INFO - 2015-10-23 14:05:26,161 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:711:7
14:05:26 INFO - 2015-10-23 14:05:26,161 DEBUG : BROWSER_OUTPUT: TaskImpl_run@resource://gre/modules/Task.jsm:319:13
14:05:26 INFO - 2015-10-23 14:05:26,161 DEBUG : BROWSER_OUTPUT: Spinner.prototype.observe@resource://gre/modules/AsyncShutdown.jsm:523:9
14:05:26 INFO - 2015-10-23 14:05:26,161 DEBUG : BROWSER_OUTPUT:
14:05:26 INFO - 2015-10-23 14:05:26,602 INFO : Browser initialized.
14:05:26 INFO - 2015-10-23 14:05:26,602 INFO : Running cycle 1/10 for sessionrestore test...
14:05:26 INFO - 2015-10-23 14:05:26,602 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile/sessionstore.js
14:05:26 INFO - 2015-10-23 14:05:26,605 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile/sessionCheckpoints.json
14:05:26 INFO - 2015-10-23 14:05:26,606 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile http://localhost:49269/startup_test/sessionrestore/index.html
14:05:31 INFO - 2015-10-23 14:05:31,636 DEBUG : BROWSER_OUTPUT: __start_report2664__end_report
14:05:31 INFO - 2015-10-23 14:05:31,636 DEBUG : BROWSER_OUTPUT:
14:05:31 INFO - 2015-10-23 14:05:31,636 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634331630__endTimestamp
14:05:31 INFO - 2015-10-23 14:05:31,636 DEBUG : BROWSER_OUTPUT:
14:05:32 INFO - 2015-10-23 14:05:32,907 INFO : Browser exited with error code: 0
14:05:32 INFO - 2015-10-23 14:05:32,909 INFO : Running cycle 2/10 for sessionrestore test...
14:05:32 INFO - 2015-10-23 14:05:32,909 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile/sessionstore.js
14:05:32 INFO - 2015-10-23 14:05:32,929 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile/sessionCheckpoints.json
14:05:32 INFO - 2015-10-23 14:05:32,929 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile http://localhost:49269/startup_test/sessionrestore/index.html
14:05:37 INFO - 2015-10-23 14:05:37,330 DEBUG : BROWSER_OUTPUT: __start_report2364__end_report
14:05:37 INFO - 2015-10-23 14:05:37,330 DEBUG : BROWSER_OUTPUT:
14:05:37 INFO - 2015-10-23 14:05:37,330 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634337329__endTimestamp
14:05:37 INFO - 2015-10-23 14:05:37,330 DEBUG : BROWSER_OUTPUT:
14:05:38 INFO - 2015-10-23 14:05:38,670 INFO : Browser exited with error code: 0
14:05:38 INFO - 2015-10-23 14:05:38,671 INFO : Running cycle 3/10 for sessionrestore test...
14:05:38 INFO - 2015-10-23 14:05:38,671 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile/sessionstore.js
14:05:38 INFO - 2015-10-23 14:05:38,674 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile/sessionCheckpoints.json
14:05:38 INFO - 2015-10-23 14:05:38,675 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile http://localhost:49269/startup_test/sessionrestore/index.html
14:05:43 INFO - 2015-10-23 14:05:43,085 DEBUG : BROWSER_OUTPUT: __start_report2370__end_report
14:05:43 INFO - 2015-10-23 14:05:43,085 DEBUG : BROWSER_OUTPUT:
14:05:43 INFO - 2015-10-23 14:05:43,086 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634343081__endTimestamp
14:05:43 INFO - 2015-10-23 14:05:43,086 DEBUG : BROWSER_OUTPUT:
14:05:44 INFO - 2015-10-23 14:05:44,447 INFO : Browser exited with error code: 0
14:05:44 INFO - 2015-10-23 14:05:44,448 INFO : Running cycle 4/10 for sessionrestore test...
14:05:44 INFO - 2015-10-23 14:05:44,448 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile/sessionstore.js
14:05:44 INFO - 2015-10-23 14:05:44,452 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile/sessionCheckpoints.json
14:05:44 INFO - 2015-10-23 14:05:44,452 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile http://localhost:49269/startup_test/sessionrestore/index.html
14:05:48 INFO - 2015-10-23 14:05:48,917 DEBUG : BROWSER_OUTPUT: __start_report2394__end_report
14:05:48 INFO - 2015-10-23 14:05:48,917 DEBUG : BROWSER_OUTPUT:
14:05:48 INFO - 2015-10-23 14:05:48,917 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634348913__endTimestamp
14:05:48 INFO - 2015-10-23 14:05:48,917 DEBUG : BROWSER_OUTPUT:
14:05:50 INFO - 2015-10-23 14:05:50,351 INFO : Browser exited with error code: 0
14:05:50 INFO - 2015-10-23 14:05:50,353 INFO : Running cycle 5/10 for sessionrestore test...
14:05:50 INFO - 2015-10-23 14:05:50,353 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile/sessionstore.js
14:05:50 INFO - 2015-10-23 14:05:50,355 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile/sessionCheckpoints.json
14:05:50 INFO - 2015-10-23 14:05:50,355 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile http://localhost:49269/startup_test/sessionrestore/index.html
14:05:54 INFO - 2015-10-23 14:05:54,779 DEBUG : BROWSER_OUTPUT: __start_report2376__end_report
14:05:54 INFO - 2015-10-23 14:05:54,779 DEBUG : BROWSER_OUTPUT:
14:05:54 INFO - 2015-10-23 14:05:54,779 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634354775__endTimestamp
14:05:54 INFO - 2015-10-23 14:05:54,779 DEBUG : BROWSER_OUTPUT:
14:05:56 INFO - 2015-10-23 14:05:56,217 INFO : Browser exited with error code: 0
14:05:56 INFO - 2015-10-23 14:05:56,218 INFO : Running cycle 6/10 for sessionrestore test...
14:05:56 INFO - 2015-10-23 14:05:56,218 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile/sessionstore.js
14:05:56 INFO - 2015-10-23 14:05:56,235 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile/sessionCheckpoints.json
14:05:56 INFO - 2015-10-23 14:05:56,235 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile http://localhost:49269/startup_test/sessionrestore/index.html
14:06:00 INFO - 2015-10-23 14:06:00,666 DEBUG : BROWSER_OUTPUT: __start_report2385__end_report
14:06:00 INFO - 2015-10-23 14:06:00,666 DEBUG : BROWSER_OUTPUT:
14:06:00 INFO - 2015-10-23 14:06:00,666 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634360665__endTimestamp
14:06:00 INFO - 2015-10-23 14:06:00,666 DEBUG : BROWSER_OUTPUT:
14:06:02 INFO - 2015-10-23 14:06:02,134 INFO : Browser exited with error code: 0
14:06:02 INFO - 2015-10-23 14:06:02,136 INFO : Running cycle 7/10 for sessionrestore test...
14:06:02 INFO - 2015-10-23 14:06:02,136 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile/sessionstore.js
14:06:02 INFO - 2015-10-23 14:06:02,141 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile/sessionCheckpoints.json
14:06:02 INFO - 2015-10-23 14:06:02,142 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile http://localhost:49269/startup_test/sessionrestore/index.html
14:06:06 INFO - 2015-10-23 14:06:06,546 DEBUG : BROWSER_OUTPUT: __start_report2369__end_report
14:06:06 INFO - 2015-10-23 14:06:06,547 DEBUG : BROWSER_OUTPUT:
14:06:06 INFO - 2015-10-23 14:06:06,547 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634366543__endTimestamp
14:06:06 INFO - 2015-10-23 14:06:06,547 DEBUG : BROWSER_OUTPUT:
14:06:07 INFO - 2015-10-23 14:06:07,961 INFO : Browser exited with error code: 0
14:06:07 INFO - 2015-10-23 14:06:07,962 INFO : Running cycle 8/10 for sessionrestore test...
14:06:07 INFO - 2015-10-23 14:06:07,962 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile/sessionstore.js
14:06:07 INFO - 2015-10-23 14:06:07,985 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile/sessionCheckpoints.json
14:06:07 INFO - 2015-10-23 14:06:07,986 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile http://localhost:49269/startup_test/sessionrestore/index.html
14:06:12 INFO - 2015-10-23 14:06:12,404 DEBUG : BROWSER_OUTPUT: __start_report2373__end_report
14:06:12 INFO - 2015-10-23 14:06:12,404 DEBUG : BROWSER_OUTPUT:
14:06:12 INFO - 2015-10-23 14:06:12,404 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634372399__endTimestamp
14:06:12 INFO - 2015-10-23 14:06:12,404 DEBUG : BROWSER_OUTPUT:
14:06:13 INFO - 2015-10-23 14:06:13,846 INFO : Browser exited with error code: 0
14:06:13 INFO - 2015-10-23 14:06:13,848 INFO : Running cycle 9/10 for sessionrestore test...
14:06:13 INFO - 2015-10-23 14:06:13,848 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile/sessionstore.js
14:06:13 INFO - 2015-10-23 14:06:13,854 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile/sessionCheckpoints.json
14:06:13 INFO - 2015-10-23 14:06:13,854 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile http://localhost:49269/startup_test/sessionrestore/index.html
14:06:18 INFO - 2015-10-23 14:06:18,286 DEBUG : BROWSER_OUTPUT: __start_report2363__end_report
14:06:18 INFO - 2015-10-23 14:06:18,287 DEBUG : BROWSER_OUTPUT:
14:06:18 INFO - 2015-10-23 14:06:18,287 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634378285__endTimestamp
14:06:18 INFO - 2015-10-23 14:06:18,287 DEBUG : BROWSER_OUTPUT:
14:06:19 INFO - 2015-10-23 14:06:19,728 INFO : Browser exited with error code: 0
14:06:19 INFO - 2015-10-23 14:06:19,729 INFO : Running cycle 10/10 for sessionrestore test...
14:06:19 INFO - 2015-10-23 14:06:19,729 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile/sessionstore.js
14:06:19 INFO - 2015-10-23 14:06:19,738 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile/sessionCheckpoints.json
14:06:19 INFO - 2015-10-23 14:06:19,738 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpd1WW8V/profile http://localhost:49269/startup_test/sessionrestore/index.html
14:06:24 INFO - 2015-10-23 14:06:24,167 DEBUG : BROWSER_OUTPUT: __start_report2383__end_report
14:06:24 INFO - 2015-10-23 14:06:24,167 DEBUG : BROWSER_OUTPUT:
14:06:24 INFO - 2015-10-23 14:06:24,167 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634384162__endTimestamp
14:06:24 INFO - 2015-10-23 14:06:24,167 DEBUG : BROWSER_OUTPUT:
14:06:25 INFO - 2015-10-23 14:06:25,635 INFO : Browser exited with error code: 0
14:06:25 INFO - 2015-10-23 14:06:25,659 INFO : Completed test sessionrestore (00:01:05)
14:06:25 INFO - 2015-10-23 14:06:25,659 INFO : Starting test sessionrestore_no_auto_restore
14:06:25 INFO - 2015-10-23 14:06:25,659 DEBUG : operating with platform_type : mac_
14:06:25 INFO - 2015-10-23 14:06:25,660 INFO : Initialising browser for sessionrestore_no_auto_restore test...
14:06:25 INFO - 2015-10-23 14:06:25,681 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile http://localhost:49269/getInfo.html
14:06:27 INFO - 2015-10-23 14:06:27,905 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200
14:06:27 INFO - 2015-10-23 14:06:27,905 DEBUG : BROWSER_OUTPUT: colorDepth:24
14:06:27 INFO - 2015-10-23 14:06:27,905 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1200/743
14:06:27 INFO - 2015-10-23 14:06:27,905 DEBUG : BROWSER_OUTPUT: __metrics
14:06:27 INFO - 2015-10-23 14:06:27,921 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]
14:06:28 INFO - 2015-10-23 14:06:28,193 DEBUG : BROWSER_OUTPUT: console.error:
14:06:28 INFO - 2015-10-23 14:06:28,193 DEBUG : BROWSER_OUTPUT: Message: [Exception... "Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [mozIStorageAsyncStatement.executeAsync]" nsresult: "0x80040111 (NS_ERROR_NOT_AVAILABLE)" location: "JS frame :: resource://gre/modules/Sqlite.jsm :: ConnectionData.prototype<._executeStatement :: line 758" data: no]
14:06:28 INFO - 2015-10-23 14:06:28,194 DEBUG : BROWSER_OUTPUT: Stack:
14:06:28 INFO - 2015-10-23 14:06:28,194 DEBUG : BROWSER_OUTPUT: ConnectionData.prototype<._executeStatement@resource://gre/modules/Sqlite.jsm:758:19
14:06:28 INFO - 2015-10-23 14:06:28,194 DEBUG : BROWSER_OUTPUT: ConnectionData.prototype<.executeCached/<@resource://gre/modules/Sqlite.jsm:493:9
14:06:28 INFO - 2015-10-23 14:06:28,194 DEBUG : BROWSER_OUTPUT: ConnectionData.prototype<.executeCached@resource://gre/modules/Sqlite.jsm:491:1
14:06:28 INFO - 2015-10-23 14:06:28,194 DEBUG : BROWSER_OUTPUT: ConnectionData.prototype<.executeBeforeShutdown/loggedDb<.executeCached.value<@resource://gre/modules/Sqlite.jsm:368:51
14:06:28 INFO - 2015-10-23 14:06:28,194 DEBUG : BROWSER_OUTPUT: TaskImpl_run@resource://gre/modules/Task.jsm:314:40
14:06:28 INFO - 2015-10-23 14:06:28,194 DEBUG : BROWSER_OUTPUT: TaskImpl@resource://gre/modules/Task.jsm:275:3
14:06:28 INFO - 2015-10-23 14:06:28,194 DEBUG : BROWSER_OUTPUT: createAsyncFunction/asyncFunction@resource://gre/modules/Task.jsm:249:14
14:06:28 INFO - 2015-10-23 14:06:28,194 DEBUG : BROWSER_OUTPUT: setAncestorsLastModified<@resource://gre/modules/Bookmarks.jsm:1347:9
14:06:28 INFO - 2015-10-23 14:06:28,194 DEBUG : BROWSER_OUTPUT: TaskImpl_run@resource://gre/modules/Task.jsm:314:40
14:06:28 INFO - 2015-10-23 14:06:28,194 DEBUG : BROWSER_OUTPUT: TaskImpl@resource://gre/modules/Task.jsm:275:3
14:06:28 INFO - 2015-10-23 14:06:28,195 DEBUG : BROWSER_OUTPUT: createAsyncFunction/asyncFunction@resource://gre/modules/Task.jsm:249:14
14:06:28 INFO - 2015-10-23 14:06:28,195 DEBUG : BROWSER_OUTPUT: transaction@resource://gre/modules/Bookmarks.jsm:808:13
14:06:28 INFO - 2015-10-23 14:06:28,195 DEBUG : BROWSER_OUTPUT: TaskImpl_run@resource://gre/modules/Task.jsm:314:40
14:06:28 INFO - 2015-10-23 14:06:28,195 DEBUG : BROWSER_OUTPUT: Handler.prototype.process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:934:23
14:06:28 INFO - 2015-10-23 14:06:28,195 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:813:7
14:06:28 INFO - 2015-10-23 14:06:28,195 DEBUG : BROWSER_OUTPUT: Promise*this.PromiseWalker.scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:744:11
14:06:28 INFO - 2015-10-23 14:06:28,195 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:776:7
14:06:28 INFO - 2015-10-23 14:06:28,195 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:711:7
14:06:28 INFO - 2015-10-23 14:06:28,195 DEBUG : BROWSER_OUTPUT: TaskImpl_run@resource://gre/modules/Task.jsm:319:13
14:06:28 INFO - 2015-10-23 14:06:28,195 DEBUG : BROWSER_OUTPUT: Spinner.prototype.observe@resource://gre/modules/AsyncShutdown.jsm:523:9
14:06:28 INFO - 2015-10-23 14:06:28,195 DEBUG : BROWSER_OUTPUT:
14:06:28 INFO - 2015-10-23 14:06:28,635 INFO : Browser initialized.
14:06:28 INFO - 2015-10-23 14:06:28,635 INFO : Running cycle 1/10 for sessionrestore_no_auto_restore test...
14:06:28 INFO - 2015-10-23 14:06:28,635 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile/sessionstore.js
14:06:28 INFO - 2015-10-23 14:06:28,641 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile/sessionCheckpoints.json
14:06:28 INFO - 2015-10-23 14:06:28,642 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile http://localhost:49269/startup_test/sessionrestore/index.html
14:06:30 INFO - 2015-10-23 14:06:30,506 DEBUG : BROWSER_OUTPUT: __start_report1278__end_report
14:06:30 INFO - 2015-10-23 14:06:30,506 DEBUG : BROWSER_OUTPUT:
14:06:30 INFO - 2015-10-23 14:06:30,507 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634390505__endTimestamp
14:06:30 INFO - 2015-10-23 14:06:30,507 DEBUG : BROWSER_OUTPUT:
14:06:31 INFO - 2015-10-23 14:06:31,223 INFO : Browser exited with error code: 0
14:06:31 INFO - 2015-10-23 14:06:31,224 INFO : Running cycle 2/10 for sessionrestore_no_auto_restore test...
14:06:31 INFO - 2015-10-23 14:06:31,224 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile/sessionstore.js
14:06:31 INFO - 2015-10-23 14:06:31,230 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile/sessionCheckpoints.json
14:06:31 INFO - 2015-10-23 14:06:31,230 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile http://localhost:49269/startup_test/sessionrestore/index.html
14:06:32 INFO - 2015-10-23 14:06:32,655 DEBUG : BROWSER_OUTPUT: __start_report980__end_report
14:06:32 INFO - 2015-10-23 14:06:32,656 DEBUG : BROWSER_OUTPUT:
14:06:32 INFO - 2015-10-23 14:06:32,656 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634392648__endTimestamp
14:06:32 INFO - 2015-10-23 14:06:32,656 DEBUG : BROWSER_OUTPUT:
14:06:33 INFO - 2015-10-23 14:06:33,347 INFO : Browser exited with error code: 0
14:06:33 INFO - 2015-10-23 14:06:33,349 INFO : Running cycle 3/10 for sessionrestore_no_auto_restore test...
14:06:33 INFO - 2015-10-23 14:06:33,349 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile/sessionstore.js
14:06:33 INFO - 2015-10-23 14:06:33,354 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile/sessionCheckpoints.json
14:06:33 INFO - 2015-10-23 14:06:33,355 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile http://localhost:49269/startup_test/sessionrestore/index.html
14:06:34 INFO - 2015-10-23 14:06:34,767 DEBUG : BROWSER_OUTPUT: __start_report972__end_report
14:06:34 INFO - 2015-10-23 14:06:34,768 DEBUG : BROWSER_OUTPUT:
14:06:34 INFO - 2015-10-23 14:06:34,768 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634394765__endTimestamp
14:06:34 INFO - 2015-10-23 14:06:34,768 DEBUG : BROWSER_OUTPUT:
14:06:35 INFO - 2015-10-23 14:06:35,538 INFO : Browser exited with error code: 0
14:06:35 INFO - 2015-10-23 14:06:35,539 INFO : Running cycle 4/10 for sessionrestore_no_auto_restore test...
14:06:35 INFO - 2015-10-23 14:06:35,539 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile/sessionstore.js
14:06:35 INFO - 2015-10-23 14:06:35,545 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile/sessionCheckpoints.json
14:06:35 INFO - 2015-10-23 14:06:35,546 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile http://localhost:49269/startup_test/sessionrestore/index.html
14:06:36 INFO - 2015-10-23 14:06:36,972 DEBUG : BROWSER_OUTPUT: __start_report983__end_report
14:06:36 INFO - 2015-10-23 14:06:36,973 DEBUG : BROWSER_OUTPUT:
14:06:36 INFO - 2015-10-23 14:06:36,973 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634396969__endTimestamp
14:06:36 INFO - 2015-10-23 14:06:36,973 DEBUG : BROWSER_OUTPUT:
14:06:37 INFO - 2015-10-23 14:06:37,746 INFO : Browser exited with error code: 0
14:06:37 INFO - 2015-10-23 14:06:37,747 INFO : Running cycle 5/10 for sessionrestore_no_auto_restore test...
14:06:37 INFO - 2015-10-23 14:06:37,748 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile/sessionstore.js
14:06:37 INFO - 2015-10-23 14:06:37,756 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile/sessionCheckpoints.json
14:06:37 INFO - 2015-10-23 14:06:37,757 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile http://localhost:49269/startup_test/sessionrestore/index.html
14:06:39 INFO - 2015-10-23 14:06:39,170 DEBUG : BROWSER_OUTPUT: __start_report965__end_report
14:06:39 INFO - 2015-10-23 14:06:39,171 DEBUG : BROWSER_OUTPUT:
14:06:39 INFO - 2015-10-23 14:06:39,171 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634399167__endTimestamp
14:06:39 INFO - 2015-10-23 14:06:39,171 DEBUG : BROWSER_OUTPUT:
14:06:39 INFO - 2015-10-23 14:06:39,990 INFO : Browser exited with error code: 0
14:06:39 INFO - 2015-10-23 14:06:39,991 INFO : Running cycle 6/10 for sessionrestore_no_auto_restore test...
14:06:39 INFO - 2015-10-23 14:06:39,992 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile/sessionstore.js
14:06:39 INFO - 2015-10-23 14:06:39,998 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile/sessionCheckpoints.json
14:06:39 INFO - 2015-10-23 14:06:39,998 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile http://localhost:49269/startup_test/sessionrestore/index.html
14:06:41 INFO - 2015-10-23 14:06:41,422 DEBUG : BROWSER_OUTPUT: __start_report968__end_report
14:06:41 INFO - 2015-10-23 14:06:41,422 DEBUG : BROWSER_OUTPUT:
14:06:41 INFO - 2015-10-23 14:06:41,423 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634401417__endTimestamp
14:06:41 INFO - 2015-10-23 14:06:41,423 DEBUG : BROWSER_OUTPUT:
14:06:42 INFO - 2015-10-23 14:06:42,221 INFO : Browser exited with error code: 0
14:06:42 INFO - 2015-10-23 14:06:42,223 INFO : Running cycle 7/10 for sessionrestore_no_auto_restore test...
14:06:42 INFO - 2015-10-23 14:06:42,223 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile/sessionstore.js
14:06:42 INFO - 2015-10-23 14:06:42,232 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile/sessionCheckpoints.json
14:06:42 INFO - 2015-10-23 14:06:42,232 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile http://localhost:49269/startup_test/sessionrestore/index.html
14:06:43 INFO - 2015-10-23 14:06:43,656 DEBUG : BROWSER_OUTPUT: __start_report970__end_report
14:06:43 INFO - 2015-10-23 14:06:43,657 DEBUG : BROWSER_OUTPUT:
14:06:43 INFO - 2015-10-23 14:06:43,657 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634403650__endTimestamp
14:06:43 INFO - 2015-10-23 14:06:43,657 DEBUG : BROWSER_OUTPUT:
14:06:44 INFO - 2015-10-23 14:06:44,482 INFO : Browser exited with error code: 0
14:06:44 INFO - 2015-10-23 14:06:44,483 INFO : Running cycle 8/10 for sessionrestore_no_auto_restore test...
14:06:44 INFO - 2015-10-23 14:06:44,484 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile/sessionstore.js
14:06:44 INFO - 2015-10-23 14:06:44,489 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile/sessionCheckpoints.json
14:06:44 INFO - 2015-10-23 14:06:44,489 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile http://localhost:49269/startup_test/sessionrestore/index.html
14:06:45 INFO - 2015-10-23 14:06:45,923 DEBUG : BROWSER_OUTPUT: __start_report976__end_report
14:06:45 INFO - 2015-10-23 14:06:45,923 DEBUG : BROWSER_OUTPUT:
14:06:45 INFO - 2015-10-23 14:06:45,923 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634405920__endTimestamp
14:06:45 INFO - 2015-10-23 14:06:45,923 DEBUG : BROWSER_OUTPUT:
14:06:46 INFO - 2015-10-23 14:06:46,744 INFO : Browser exited with error code: 0
14:06:46 INFO - 2015-10-23 14:06:46,746 INFO : Running cycle 9/10 for sessionrestore_no_auto_restore test...
14:06:46 INFO - 2015-10-23 14:06:46,746 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile/sessionstore.js
14:06:46 INFO - 2015-10-23 14:06:46,754 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile/sessionCheckpoints.json
14:06:46 INFO - 2015-10-23 14:06:46,755 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile http://localhost:49269/startup_test/sessionrestore/index.html
14:06:48 INFO - 2015-10-23 14:06:48,184 DEBUG : BROWSER_OUTPUT: __start_report982__end_report
14:06:48 INFO - 2015-10-23 14:06:48,184 DEBUG : BROWSER_OUTPUT:
14:06:48 INFO - 2015-10-23 14:06:48,184 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634408183__endTimestamp
14:06:48 INFO - 2015-10-23 14:06:48,184 DEBUG : BROWSER_OUTPUT:
14:06:49 INFO - 2015-10-23 14:06:49,021 INFO : Browser exited with error code: 0
14:06:49 INFO - 2015-10-23 14:06:49,022 INFO : Running cycle 10/10 for sessionrestore_no_auto_restore test...
14:06:49 INFO - 2015-10-23 14:06:49,022 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile/sessionstore.js
14:06:49 INFO - 2015-10-23 14:06:49,028 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile/sessionCheckpoints.json
14:06:49 INFO - 2015-10-23 14:06:49,028 DEBUG : command line: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/tmpYuufqx/profile http://localhost:49269/startup_test/sessionrestore/index.html
14:06:50 INFO - 2015-10-23 14:06:50,452 DEBUG : BROWSER_OUTPUT: __start_report973__end_report
14:06:50 INFO - 2015-10-23 14:06:50,452 DEBUG : BROWSER_OUTPUT:
14:06:50 INFO - 2015-10-23 14:06:50,452 DEBUG : BROWSER_OUTPUT: __startTimestamp1445634410451__endTimestamp
14:06:50 INFO - 2015-10-23 14:06:50,452 DEBUG : BROWSER_OUTPUT:
14:06:51 INFO - 2015-10-23 14:06:51,302 INFO : Browser exited with error code: 0
14:06:51 INFO - 2015-10-23 14:06:51,324 INFO : Completed test sessionrestore_no_auto_restore (00:00:25)
14:06:51 INFO - 2015-10-23 14:06:51,349 INFO : Completed test suite (00:04:23)
14:06:51 INFO - 2015-10-23 14:06:51,350 DEBUG : Working with test: a11yr
14:06:51 INFO - 2015-10-23 14:06:51,350 DEBUG : Generating results file: a11yr
14:06:51 INFO - 2015-10-23 14:06:51,350 DEBUG : Working with test: ts_paint
14:06:51 INFO - 2015-10-23 14:06:51,350 DEBUG : Generating results file: ts_paint
14:06:51 INFO - 2015-10-23 14:06:51,350 DEBUG : Working with test: tpaint
14:06:51 INFO - 2015-10-23 14:06:51,350 DEBUG : Generating results file: tpaint
14:06:51 INFO - 2015-10-23 14:06:51,351 DEBUG : Working with test: sessionrestore
14:06:51 INFO - 2015-10-23 14:06:51,351 DEBUG : Generating results file: sessionrestore
14:06:51 INFO - 2015-10-23 14:06:51,351 DEBUG : Working with test: sessionrestore_no_auto_restore
14:06:51 INFO - 2015-10-23 14:06:51,351 DEBUG : Generating results file: sessionrestore_no_auto_restore
14:06:51 INFO - 2015-10-23 14:06:51,351 INFO : Posting result 0 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
14:06:51 INFO - 2015-10-23 14:06:51,391 DEBUG : process_Request line: a11yr_paint graph.html#tests=[[223,64,55]]
14:06:51 INFO - 2015-10-23 14:06:51,391 DEBUG : process_Request line: a11yr_paint 545.45 graph.html#tests=[[223,64,55]]
14:06:51 INFO - 2015-10-23 14:06:51,391 INFO : Posting result 1 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
14:06:51 INFO - 2015-10-23 14:06:51,449 DEBUG : process_Request line: ts_paint graph.html#tests=[[83,64,55]]
14:06:51 INFO - 2015-10-23 14:06:51,449 DEBUG : process_Request line: ts_paint 1287.98 graph.html#tests=[[83,64,55]]
14:06:51 INFO - 2015-10-23 14:06:51,449 INFO : Posting result 2 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
14:06:51 INFO - 2015-10-23 14:06:51,491 DEBUG : process_Request line: tpaint graph.html#tests=[[82,64,55]]
14:06:51 INFO - 2015-10-23 14:06:51,491 DEBUG : process_Request line: tpaint 333.64 graph.html#tests=[[82,64,55]]
14:06:51 INFO - 2015-10-23 14:06:51,491 INFO : Posting result 3 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
14:06:51 INFO - 2015-10-23 14:06:51,543 DEBUG : process_Request line: sessionrestore graph.html#tests=[[313,64,55]]
14:06:51 INFO - 2015-10-23 14:06:51,544 DEBUG : process_Request line: sessionrestore 2402.61 graph.html#tests=[[313,64,55]]
14:06:51 INFO - 2015-10-23 14:06:51,544 INFO : Posting result 4 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0
14:06:51 INFO - 2015-10-23 14:06:51,603 DEBUG : process_Request line: sessionrestore_no_auto_restore graph.html#tests=[[315,64,55]]
14:06:51 INFO - 2015-10-23 14:06:51,603 DEBUG : process_Request line: sessionrestore_no_auto_restore 1001.11 graph.html#tests=[[315,64,55]]
14:06:51 INFO - 2015-10-23 14:06:51,604 INFO : TALOSDATA: [{"talos_counters": {}, "results": {"dhtml.html": [1109.0, 1141.0, 1059.0, 1146.0, 1144.0, 1145.0, 1142.0, 1147.0, 1181.0, 1147.0, 1155.0, 1153.0, 1063.0, 1183.0, 1062.0, 1184.0, 1156.0, 1143.0, 1148.0, 1161.0, 1149.0, 1150.0, 1143.0, 1153.0, 1155.0], "tablemutation.html": [264.0, 262.0, 267.0, 258.0, 259.0, 260.0, 258.0, 259.0, 259.0, 257.0, 258.0, 259.0, 260.0, 259.0, 259.0, 259.0, 261.0, 261.0, 259.0, 259.0, 260.0, 259.0, 260.0, 259.0, 258.0]}, "summary": {"suite": 545.4521937004189, "subtests": {"dhtml.html": {"filtered": 1147.5, "value": 1147.5}, "tablemutation.html": {"filtered": 259.0, "value": 259.0}}}, "test_machine": {"platform": "x86_64", "osversion": "OS X 10.10.2", "os": "mac", "name": "t-yosemite-r5-0016"}, "testrun": {"date": 1445634148, "suite": "a11yr", "options": {"responsiveness": false, "tpmozafterpaint": true, "tpchrome": true, "tppagecycles": 25, "tpcycles": 1, "tprender": false, "shutdown": false, "cycles": 1, "rss": false}}, "test_build": {"name": "Firefox", "version": "44.0a1", "id": "20151023121232", "branch": "Fx-Team", "revision": "ccb7bb578fb15e0fe344b0e9a3b3628faed8bedc"}}, {"talos_counters": {}, "results": {"ts_paint": [1714.0, 1264.0, 1270.0, 1260.0, 1261.0, 1267.0, 1270.0, 1255.0, 1264.0, 1264.0, 1288.0, 1269.0, 1261.0, 1291.0, 1271.0, 1291.0, 1266.0, 1260.0, 1269.0, 1266.0]}, "summary": {"suite": 1266.0, "subtests": {"ts_paint": {"filtered": 1266.0, "value": 1266.0}}}, "test_machine": {"platform": "x86_64", "osversion": "OS X 10.10.2", "os": "mac", "name": "t-yosemite-r5-0016"}, "testrun": {"date": 1445634148, "suite": "ts_paint", "options": {"responsiveness": false, "cycles": 20, "tpmozafterpaint": true, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "44.0a1", "id": "20151023121232", "branch": "Fx-Team", "revision": "ccb7bb578fb15e0fe344b0e9a3b3628faed8bedc"}}, {"talos_counters": {}, "results": {"tpaint": [308.40499999999975, 312.60000000000036, 314.58500000000004, 316.6750000000002, 317.3250000000007, 319.28500000000076, 324.3050000000003, 324.4150000000009, 326.16499999999905, 326.72000000000116, 327.2449999999999, 332.02999999999884, 333.6350000000002, 339.375, 342.7099999999991, 345.5099999999984, 359.58500000000276, 404.65500000000065, 405.5300000000025, 505.35000000000036]}, "summary": {"suite": 333.6350000000002, "subtests": {"tpaint": {"filtered": 333.6350000000002, "value": 333.6350000000002}}}, "test_machine": {"platform": "x86_64", "osversion": "OS X 10.10.2", "os": "mac", "name": "t-yosemite-r5-0016"}, "testrun": {"date": 1445634148, "suite": "tpaint", "options": {"responsiveness": false, "cycles": 1, "tpmozafterpaint": true, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "44.0a1", "id": "20151023121232", "branch": "Fx-Team", "revision": "ccb7bb578fb15e0fe344b0e9a3b3628faed8bedc"}}, {"talos_counters": {}, "results": {"sessionrestore": [2664.0, 2364.0, 2370.0, 2394.0, 2376.0, 2385.0, 2369.0, 2373.0, 2363.0, 2383.0]}, "summary": {"suite": 2373.0, "subtests": {"sessionrestore": {"filtered": 2373.0, "value": 2373.0}}}, "test_machine": {"platform": "x86_64", "osversion": "OS X 10.10.2", "os": "mac", "name": "t-yosemite-r5-0016"}, "testrun": {"date": 1445634148, "suite": "sessionrestore", "options": {"responsiveness": false, "cycles": 10, "tpmozafterpaint": false, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "44.0a1", "id": "20151023121232", "branch": "Fx-Team", "revision": "ccb7bb578fb15e0fe344b0e9a3b3628faed8bedc"}}, {"talos_counters": {}, "results": {"sessionrestore_no_auto_restore": [1278.0, 980.0, 972.0, 983.0, 965.0, 968.0, 970.0, 976.0, 982.0, 973.0]}, "summary": {"suite": 973.0, "subtests": {"sessionrestore_no_auto_restore": {"filtered": 973.0, "value": 973.0}}}, "test_machine": {"platform": "x86_64", "osversion": "OS X 10.10.2", "os": "mac", "name": "t-yosemite-r5-0016"}, "testrun": {"date": 1445634148, "suite": "sessionrestore_no_auto_restore", "options": {"responsiveness": false, "cycles": 10, "tpmozafterpaint": false, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "44.0a1", "id": "20151023121232", "branch": "Fx-Team", "revision": "ccb7bb578fb15e0fe344b0e9a3b3628faed8bedc"}}]
14:06:51 INFO - RETURN: a11yr_paint: 545.45
14:06:51 INFO - RETURN: ts_paint: 1287.98
14:06:51 INFO - RETURN: tpaint: 333.64
14:06:51 INFO - RETURN: sessionrestore: 2402.61
14:06:51 INFO - RETURN: sessionrestore_no_auto_restore: 1001.11
14:06:51 INFO - TinderboxPrint: TalosResult: {"graphserver": {"sessionrestore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[313,64,55]]", "result": "2402.61"}, "a11yr_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[223,64,55]]", "result": "545.45"}, "tpaint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[82,64,55]]", "result": "333.64"}, "ts_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[83,64,55]]", "result": "1287.98"}, "sessionrestore_no_auto_restore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[315,64,55]]", "result": "1001.11"}}}
14:06:51 INFO - Return code: 0
14:06:51 INFO - # TBPL SUCCESS #
14:06:51 INFO - Running pre test command check_screen_resolution with 'bash -c screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'
14:06:51 INFO - Running command: ['bash', '-c', 'screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'] in /builds/slave/test/build
14:06:51 INFO - Copy/paste: bash -c "screenresolution get && screenresolution list && system_profiler SPDisplaysDataType"
14:06:51 INFO - 2015-10-23 14:06:51.684 screenresolution[1697:12503] starting screenresolution argv=screenresolution get
14:06:51 INFO - 2015-10-23 14:06:51.687 screenresolution[1697:12503] Display 0: 1600x1200x32@60
14:06:51 INFO - 2015-10-23 14:06:51.693 screenresolution[1698:12505] starting screenresolution argv=screenresolution list
14:06:51 INFO - Available Modes on Display 0
14:06:51 INFO - 1600x1200x32@60 1152x870x32@75 1280x1024x32@75
14:06:51 INFO - 1024x768x32@75 1024x768x32@70 1024x768x32@60
14:06:51 INFO - 800x600x32@75 800x600x32@60 640x480x32@75
14:06:51 INFO - 640x480x32@60 1280x1024x32@60 1280x960x32@60
14:06:51 INFO - 1280x960x32@75 1344x1008x32@60 Graphics/Displays:
14:06:51 INFO - Intel HD Graphics 3000:
14:06:51 INFO - Chipset Model: Intel HD Graphics 3000
14:06:51 INFO - Type: GPU
14:06:51 INFO - Bus: Built-In
14:06:51 INFO - VRAM (Total): 512 MB
14:06:51 INFO - VRAM (Dynamic, Max): 10
14:06:51 INFO - Vendor: Intel (0x8086)
14:06:51 INFO - Device ID: 0x0116
14:06:51 INFO - Revision ID: 0x0009
14:06:51 INFO - Displays:
14:06:51 INFO - Display:
14:06:51 INFO - Resolution: 1600 x 1200 @ 60 Hz
14:06:51 INFO - Pixel Depth: 32-Bit Color (ARGB8888)
14:06:51 INFO - Display Serial Number: 1600x1200 60
14:06:51 INFO - Main Display: Yes
14:06:51 INFO - Mirror: Off
14:06:51 INFO - Online: Yes
14:06:51 INFO - Rotation: Supported
14:06:51 INFO - Return code: 0
14:06:51 INFO - Running post-action listener: _resource_record_post_action
14:06:51 INFO - Running post-run listener: _resource_record_post_run
14:06:52 INFO - Total resource usage - Wall time: 300s; CPU: 29.0%; Read bytes: 36234240; Write bytes: 595390464; Read time: 4155; Write time: 17720
14:06:52 INFO - install - Wall time: 36s; CPU: 30.0%; Read bytes: 337797632; Write bytes: 332773376; Read time: 31685; Write time: 3826
14:06:52 INFO - run-tests - Wall time: 264s; CPU: 29.0%; Read bytes: 34231296; Write bytes: 251484160; Read time: 3812; Write time: 12784
14:06:52 INFO - Running post-run listener: _upload_blobber_files
14:06:52 INFO - Blob upload gear active.
14:06:52 INFO - There are no files to upload in the directory. Skipping the blob upload mechanism ...
14:06:52 INFO - Copying logs to upload dir...
14:06:52 INFO - mkdir: /builds/slave/test/build/upload/logs
program finished with exit code 0
elapsedTime=356.510944
========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 6 mins, 49 secs) (at 2015-10-23 14:07:45.786564) =========
========= Started set props: build_url (results: 0, elapsed: 0 secs) (at 2015-10-23 14:07:45.790734) =========
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:
Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.hzmkYpjbIV/Render
GIT_SHARE_BASE_DIR=/builds/git-shared
HG_SHARE_BASE_DIR=/builds/hg-shared
HOME=/Users/cltbld
IDLEIZER_DISABLE_SHUTDOWN=true
LOGNAME=cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NO_EM_RESTART=1
PAGER=/bin/cat
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11
PWD=/builds/slave/test/properties
RUNNER_CONFIG_CMD=/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg
SHELL=/bin/bash
SSH_AUTH_SOCK=/private/tmp/com.apple.launchd.OlDG3iec1b/Listeners
TMPDIR=/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/
TWISTD_LOG_PATH=/builds/slave/twistd.log
USER=cltbld
VERSIONER_PYTHON_PREFER_32_BIT=no
VERSIONER_PYTHON_VERSION=2.7
XPCOM_DEBUG_BREAK=warn
XPC_FLAGS=0x0
XPC_SERVICE_NAME=0
__CF_USER_TEXT_ENCODING=0x1C:0x0:0x0
using PTY: False
build_url:https://queue.taskcluster.net/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.dmg
program finished with exit code 0
elapsedTime=0.010183
build_url: 'https://queue.taskcluster.net/v1/task/kvTtorUhSAmyPm0bPMnhMA/artifacts/public/build/firefox-44.0a1.en-US.mac.dmg'
========= Finished set props: build_url (results: 0, elapsed: 0 secs) (at 2015-10-23 14:07:46.602164) =========
========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-10-23 14:07:46.605549) =========
rm -f oauth.txt
in dir /builds/slave/test/. (timeout 1200 secs)
watching logfiles {}
argv: ['rm', '-f', 'oauth.txt']
environment:
Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.hzmkYpjbIV/Render
GIT_SHARE_BASE_DIR=/builds/git-shared
HG_SHARE_BASE_DIR=/builds/hg-shared
HOME=/Users/cltbld
IDLEIZER_DISABLE_SHUTDOWN=true
LOGNAME=cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NO_EM_RESTART=1
PAGER=/bin/cat
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11
PWD=/builds/slave/test
RUNNER_CONFIG_CMD=/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg
SHELL=/bin/bash
SSH_AUTH_SOCK=/private/tmp/com.apple.launchd.OlDG3iec1b/Listeners
TMPDIR=/var/folders/gg/q6y1_2717rsgmjth6gwwvht800000w/T/
TWISTD_LOG_PATH=/builds/slave/twistd.log
USER=cltbld
VERSIONER_PYTHON_PREFER_32_BIT=no
VERSIONER_PYTHON_VERSION=2.7
XPCOM_DEBUG_BREAK=warn
XPC_FLAGS=0x0
XPC_SERVICE_NAME=0
__CF_USER_TEXT_ENCODING=0x1C:0x0:0x0
using PTY: False
program finished with exit code 0
elapsedTime=0.005468
========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-10-23 14:07:46.691324) =========
========= Started reboot slave lost (results: 0, elapsed: 26 secs) (at 2015-10-23 14:07:46.691834) =========
========= Finished reboot slave lost (results: 0, elapsed: 26 secs) (at 2015-10-23 14:08:13.350332) =========