builder: mozilla-aurora_yosemite_test-other slave: t-yosemite-r5-0025 starttime: 1446193050.92 results: success (0) buildid: 20151029014646 builduid: e2197d6fa76745edba8eadefeb37f684 revision: 41fdefd640f368bccdeafe6446d42c0a5ad22797 ========= Started set props: master (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:30.920529) ========= master: http://buildbot-master108.bb.releng.scl3.mozilla.com:8201/ ========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:30.920943) ========= ========= Started set props: basedir (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:30.921230) ========= 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.GdR3T8lx2O/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.Xo8SBI494k/Listeners TMPDIR=/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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.005928 basedir: '/builds/slave/test' ========= Finished set props: basedir (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:31.260826) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:31.261135) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:31.284235) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:31.284707) ========= 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.GdR3T8lx2O/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.Xo8SBI494k/Listeners TMPDIR=/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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.013091 ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:31.334270) ========= ========= Started set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:31.334750) ========= script_repo_url: https://hg.mozilla.org/build/mozharness ========= Finished set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:31.335112) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:31.335384) ========= 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.GdR3T8lx2O/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.Xo8SBI494k/Listeners TMPDIR=/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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-30 01:17:31-- https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py Resolving hg.mozilla.org... 63.245.215.102, 63.245.215.102, 63.245.215.25, ... Connecting to hg.mozilla.org|63.245.215.102|:443... connected. HTTP request sent, awaiting response... 200 Script output follows Length: 12141 (12K) [text/x-python] Saving to: `archiver_client.py' 0K .......... . 100% 11.5M=0.001s 2015-10-30 01:17:31 (11.5 MB/s) - `archiver_client.py' saved [12141/12141] program finished with exit code 0 elapsedTime=0.243308 ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:31.596830) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:31.597294) ========= 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.GdR3T8lx2O/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.Xo8SBI494k/Listeners TMPDIR=/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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.070995 ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:31.685552) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:31.686314) ========= bash -c 'python archiver_client.py mozharness --repo releases/mozilla-aurora --rev 41fdefd640f368bccdeafe6446d42c0a5ad22797 --destination scripts --debug' in dir /builds/slave/test/. (timeout 1200 secs) watching logfiles {} argv: ['bash', '-c', u'python archiver_client.py mozharness --repo releases/mozilla-aurora --rev 41fdefd640f368bccdeafe6446d42c0a5ad22797 --destination scripts --debug'] environment: Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.GdR3T8lx2O/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.Xo8SBI494k/Listeners TMPDIR=/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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-30 01:17:31,774 truncating revision to first 12 chars 2015-10-30 01:17:31,774 Setting DEBUG logging. 2015-10-30 01:17:31,774 attempt 1/10 2015-10-30 01:17:31,774 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/releases/mozilla-aurora/41fdefd640f3?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness 2015-10-30 01:17:32,031 unpacking tar archive at: mozilla-aurora-41fdefd640f3/testing/mozharness/ program finished with exit code 0 elapsedTime=0.513573 ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:32.217874) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:32.218182) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:32.231327) ========= ========= Started tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:32.231631) ========= TinderboxPrint: script_revlink: https://hg.mozilla.org/build/mozharness/rev/production ========= Finished tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-10-30 01:17:32.232023) ========= ========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 6 mins, 6 secs) (at 2015-10-30 01:17:32.232304) ========= /tools/buildbot/bin/python scripts/scripts/talos_script.py --suite other --add-option --webServer,localhost --branch-name Mozilla-Aurora --system-bits 64 --cfg talos/mac_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Mozilla-Aurora in dir /builds/slave/test/. (timeout 3600 secs) (maxTime 7200 secs) watching logfiles {} argv: ['/tools/buildbot/bin/python', 'scripts/scripts/talos_script.py', '--suite', 'other', '--add-option', '--webServer,localhost', '--branch-name', 'Mozilla-Aurora', '--system-bits', '64', '--cfg', 'talos/mac_config.py', '--download-symbols', 'ondemand', '--use-talos-json', '--blob-upload-branch', 'Mozilla-Aurora'] environment: Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.GdR3T8lx2O/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.Xo8SBI494k/Listeners TMPDIR=/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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 01:17:32 INFO - MultiFileLogger online at 20151030 01:17:32 in /builds/slave/test 01:17:32 INFO - Run as scripts/scripts/talos_script.py --suite other --add-option --webServer,localhost --branch-name Mozilla-Aurora --system-bits 64 --cfg talos/mac_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Mozilla-Aurora 01:17:32 INFO - Guessing talos json url... 01:17:32 INFO - Using buildbot properties: 01:17:32 INFO - { 01:17:32 INFO - "properties": { 01:17:32 INFO - "buildnumber": 97, 01:17:32 INFO - "product": "firefox", 01:17:32 INFO - "script_repo_revision": "production", 01:17:32 INFO - "builddir": "mozilla-aurora_yosemite_test-other", 01:17:32 INFO - "repository": "", 01:17:32 INFO - "buildername": "Rev5 MacOSX Yosemite 10.10 mozilla-aurora talos other", 01:17:32 INFO - "buildid": "20151029014646", 01:17:32 INFO - "slavename": "t-yosemite-r5-0025", 01:17:32 INFO - "pgo_build": "False", 01:17:32 INFO - "basedir": "/builds/slave/test", 01:17:32 INFO - "project": "", 01:17:32 INFO - "platform": "yosemite", 01:17:32 INFO - "master": "http://buildbot-master108.bb.releng.scl3.mozilla.com:8201/", 01:17:32 INFO - "slavebuilddir": "test", 01:17:32 INFO - "scheduler": "tests-mozilla-aurora-macosx64-talos", 01:17:32 INFO - "branch": "mozilla-aurora", 01:17:32 INFO - "repo_path": "releases/mozilla-aurora", 01:17:32 INFO - "stage_platform": "macosx64", 01:17:32 INFO - "builduid": "e2197d6fa76745edba8eadefeb37f684", 01:17:32 INFO - "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797" 01:17:32 INFO - }, 01:17:32 INFO - "sourcestamp": { 01:17:32 INFO - "repository": "", 01:17:32 INFO - "hasPatch": false, 01:17:32 INFO - "project": "", 01:17:32 INFO - "branch": "mozilla-aurora-macosx64-talos", 01:17:32 INFO - "changes": [ 01:17:32 INFO - { 01:17:32 INFO - "category": null, 01:17:32 INFO - "files": [ 01:17:32 INFO - { 01:17:32 INFO - "url": null, 01:17:32 INFO - "name": "https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.dmg" 01:17:32 INFO - } 01:17:32 INFO - ], 01:17:32 INFO - "repository": "", 01:17:32 INFO - "rev": "41fdefd640f368bccdeafe6446d42c0a5ad22797", 01:17:32 INFO - "who": "jyavenard@mozilla.com", 01:17:32 INFO - "when": 1446112210, 01:17:32 INFO - "number": 6592630, 01:17:32 INFO - "comments": "Bug 1218157: Only ever read from cached data in NotifyDataArrived. r=cpearce a=lizzard\n\nThe logic of queuing NotifyDataArrived and read data there was fundamentally flawed as we would continually perform reads from the same MediaResource at two different ends.\nThis would cause repetitive seeks and data being removed from the media cache. Worse, a read in NotifyDataArrived would cause another NotifyDataArrived to be scheduled.\n\nAs range-request are extremely slow, it would result in stutters and constant interruptions.\n", 01:17:32 INFO - "project": "", 01:17:32 INFO - "at": "Thu 29 Oct 2015 02:50:10", 01:17:32 INFO - "branch": "mozilla-aurora-macosx64-talos", 01:17:32 INFO - "revlink": "", 01:17:32 INFO - "properties": [ 01:17:32 INFO - [ 01:17:32 INFO - "buildid", 01:17:32 INFO - "20151029014646", 01:17:32 INFO - "Change" 01:17:32 INFO - ], 01:17:32 INFO - [ 01:17:32 INFO - "builduid", 01:17:32 INFO - "e2197d6fa76745edba8eadefeb37f684", 01:17:32 INFO - "Change" 01:17:32 INFO - ], 01:17:32 INFO - [ 01:17:32 INFO - "pgo_build", 01:17:32 INFO - "False", 01:17:32 INFO - "Change" 01:17:32 INFO - ] 01:17:32 INFO - ], 01:17:32 INFO - "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797" 01:17:32 INFO - } 01:17:32 INFO - ], 01:17:32 INFO - "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797" 01:17:32 INFO - } 01:17:32 INFO - } 01:17:32 INFO - Found installer url https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.dmg. 01:17: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')]} 01:17:32 INFO - https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.txt matches https://queue.taskcluster.net 01:17:32 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.txt 01:17:32 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.txt 01:17:32 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.txt to /builds/slave/test/build/firefox-43.0a2.en-US.mac.txt 01:17:32 INFO - retry: Calling _download_file with args: ('http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.txt', '/builds/slave/test/build/firefox-43.0a2.en-US.mac.txt'), kwargs: {}, attempt #1 01:17:34 INFO - Downloaded 107 bytes. 01:17:34 INFO - Reading from file /builds/slave/test/build/firefox-43.0a2.en-US.mac.txt 01:17:34 INFO - Contents: 01:17:34 INFO - 20151029014646 01:17:34 INFO - https://hg.mozilla.org/releases/mozilla-aurora/rev/41fdefd640f368bccdeafe6446d42c0a5ad22797 01:17:34 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:17:34 INFO - trying https://hg.mozilla.org/releases/mozilla-aurora/raw-file/41fdefd640/testing/talos/talos.json 01:17:34 INFO - Downloading https://hg.mozilla.org/releases/mozilla-aurora/raw-file/41fdefd640/testing/talos/talos.json to /builds/slave/test/build/talos.json 01:17:34 INFO - retry: Calling _download_file with args: ('https://hg.mozilla.org/releases/mozilla-aurora/raw-file/41fdefd640/testing/talos/talos.json', '/builds/slave/test/build/talos.json'), kwargs: {}, attempt #1 01:17:35 INFO - Downloaded 6818 bytes. 01:17:35 INFO - {'extra_options': {'android': ['--apkPath=%(apk_path)s']}, 01:17:35 INFO - 'mobile-suites': {'remote-tp4m_nochrome': {'tests': ['tp4m']}, 01:17:35 INFO - 'remote-trobocheck2': {'talos_options': ['--fennecIDs', 01:17:35 INFO - '../fennec_ids.txt'], 01:17:35 INFO - 'tests': ['tcheck2']}, 01:17:35 INFO - 'remote-tsvgx': {'talos_options': ['--noChrome', 01:17:35 INFO - '--tppagecycles', 01:17:35 INFO - '7'], 01:17:35 INFO - 'tests': ['tsvgm']}}, 01:17:35 INFO - 'suites': {'chromez': {'tests': ['tresize', 'tcanvasmark']}, 01:17:35 INFO - 'chromez-e10s': {'talos_options': ['--e10s'], 01:17:35 INFO - 'tests': ['tresize', 'tcanvasmark']}, 01:17:35 INFO - 'dromaeojs': {'tests': ['dromaeo_css', 'kraken', 'v8_7']}, 01:17:35 INFO - 'dromaeojs-e10s': {'talos_options': ['--e10s'], 01:17:35 INFO - 'tests': ['dromaeo_css', 'kraken', 'v8_7']}, 01:17:35 INFO - 'g1': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5o.manifest', 01:17:35 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/', 01:17:35 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 01:17:35 INFO - 'plugins': {'32': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash32_10_3_183_5.zip', 01:17:35 INFO - '64': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash64_11_0_d1_98.zip'}, 01:17:35 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 01:17:35 INFO - 'g1-e10s': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5o.manifest', 01:17:35 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/', 01:17:35 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 01:17:35 INFO - 'plugins': {'32': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash32_10_3_183_5.zip', 01:17:35 INFO - '64': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash64_11_0_d1_98.zip'}, 01:17:35 INFO - 'talos_options': ['--e10s'], 01:17:35 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 01:17:35 INFO - 'g2': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5o.manifest', 01:17:35 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/', 01:17:35 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 01:17:35 INFO - 'tests': ['damp', 'tps']}, 01:17:35 INFO - 'g2-e10s': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5o.manifest', 01:17:35 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/', 01:17:35 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 01:17:35 INFO - 'talos_options': ['--e10s'], 01:17:35 INFO - 'tests': ['damp', 'tps']}, 01:17:35 INFO - 'g3': {'tests': ['dromaeo_dom']}, 01:17:35 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']}, 01:17:35 INFO - 'other': {'tests': ['a11yr', 01:17:35 INFO - 'ts_paint', 01:17:35 INFO - 'tpaint', 01:17:35 INFO - 'sessionrestore', 01:17:35 INFO - 'sessionrestore_no_auto_restore']}, 01:17:35 INFO - 'other-e10s': {'talos_options': ['--e10s'], 01:17:35 INFO - 'tests': ['a11yr', 01:17:35 INFO - 'ts_paint', 01:17:35 INFO - 'tpaint', 01:17:35 INFO - 'sessionrestore', 01:17:35 INFO - 'sessionrestore_no_auto_restore']}, 01:17:35 INFO - 'other-e10s_l64': {'talos_options': ['--e10s'], 01:17:35 INFO - 'tests': ['a11yr', 01:17:35 INFO - 'ts_paint', 01:17:35 INFO - 'tpaint', 01:17:35 INFO - 'sessionrestore', 01:17:35 INFO - 'sessionrestore_no_auto_restore']}, 01:17:35 INFO - 'other-e10s_nol64': {'talos_options': ['--e10s'], 01:17:35 INFO - 'tests': ['a11yr', 01:17:35 INFO - 'ts_paint', 01:17:35 INFO - 'tpaint', 01:17:35 INFO - 'sessionrestore', 01:17:35 INFO - 'sessionrestore_no_auto_restore']}, 01:17:35 INFO - 'other_l64': {'tests': ['a11yr', 01:17:35 INFO - 'ts_paint', 01:17:35 INFO - 'tpaint', 01:17:35 INFO - 'sessionrestore', 01:17:35 INFO - 'sessionrestore_no_auto_restore']}, 01:17:35 INFO - 'other_nol64': {'tests': ['a11yr', 01:17:35 INFO - 'ts_paint', 01:17:35 INFO - 'tpaint', 01:17:35 INFO - 'sessionrestore', 01:17:35 INFO - 'sessionrestore_no_auto_restore']}, 01:17:35 INFO - 'svgr': {'tests': ['tsvgx', 01:17:35 INFO - 'tsvgr_opacity', 01:17:35 INFO - 'tart', 01:17:35 INFO - 'tscrollx', 01:17:35 INFO - 'cart']}, 01:17:35 INFO - 'svgr-e10s': {'talos_options': ['--e10s'], 01:17:35 INFO - 'tests': ['tsvgx', 01:17:35 INFO - 'tsvgr_opacity', 01:17:35 INFO - 'tart', 01:17:35 INFO - 'tscrollx', 01:17:35 INFO - 'cart']}, 01:17:35 INFO - 'tp5o': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5o.manifest', 01:17:35 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/', 01:17:35 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 01:17:35 INFO - 'plugins': {'32': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash32_10_3_183_5.zip', 01:17:35 INFO - '64': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash64_11_0_d1_98.zip'}, 01:17:35 INFO - 'tests': ['tp5o']}, 01:17:35 INFO - 'tp5o-e10s': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5o.manifest', 01:17:35 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/', 01:17:35 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 01:17:35 INFO - 'plugins': {'32': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash32_10_3_183_5.zip', 01:17:35 INFO - '64': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash64_11_0_d1_98.zip'}, 01:17:35 INFO - 'talos_options': ['--e10s'], 01:17:35 INFO - 'tests': ['tp5o']}, 01:17:35 INFO - 'xperf': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5n.manifest', 01:17:35 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/', 01:17:35 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 01:17:35 INFO - 'plugins': {'32': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash32_10_3_183_5.zip', 01:17:35 INFO - '64': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash64_11_0_d1_98.zip'}, 01:17:35 INFO - 'talos_options': ['--xperf_path', 01:17:35 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 01:17:35 INFO - 'tests': ['tp5n']}, 01:17:35 INFO - 'xperf-e10s': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5n.manifest', 01:17:35 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/', 01:17:35 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 01:17:35 INFO - 'plugins': {'32': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash32_10_3_183_5.zip', 01:17:35 INFO - '64': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash64_11_0_d1_98.zip'}, 01:17:35 INFO - 'talos_options': ['--e10s', 01:17:35 INFO - '--xperf_path', 01:17:35 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"', 01:17:35 INFO - 'C:/slave/talos-data/talos/xperf.config'], 01:17:35 INFO - 'tests': ['tp5n']}}, 01:17:35 INFO - 'talos.zip': {'path': '', 01:17:35 INFO - 'url': 'http://talos-bundles.pvt.build.mozilla.org/zips/talos.a6052c33d420.zip'}} 01:17:35 INFO - Dumping config to /builds/slave/test/logs/localconfig.json. 01:17:35 INFO - {'append_to_log': False, 01:17:35 INFO - 'base_work_dir': '/builds/slave/test', 01:17:35 INFO - 'blob_upload_branch': 'Mozilla-Aurora', 01:17:35 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt', 01:17:35 INFO - 'branch': 'Mozilla-Aurora', 01:17:35 INFO - 'buildbot_json_path': 'buildprops.json', 01:17:35 INFO - 'config_files': ('talos/mac_config.py',), 01:17:35 INFO - 'default_actions': ('clobber', 01:17:35 INFO - 'read-buildbot-config', 01:17:35 INFO - 'download-and-extract', 01:17:35 INFO - 'populate-webroot', 01:17:35 INFO - 'create-virtualenv', 01:17:35 INFO - 'install', 01:17:35 INFO - 'run-tests'), 01:17:35 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 01:17:35 INFO - 'download_minidump_stackwalk': True, 01:17:35 INFO - 'download_symbols': 'ondemand', 01:17:35 INFO - 'exes': {'python': '/tools/buildbot/bin/python', 01:17:35 INFO - 'tooltool.py': '/tools/tooltool.py', 01:17:35 INFO - 'virtualenv': ('/tools/buildbot/bin/python', 01:17:35 INFO - '/tools/misc-python/virtualenv.py')}, 01:17:35 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 01:17:35 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 01:17:35 INFO - 'installer_path': 'installer.exe', 01:17:35 INFO - 'log_level': 'info', 01:17:35 INFO - 'log_name': 'talos', 01:17:35 INFO - 'log_to_console': True, 01:17:35 INFO - 'minidump_stackwalk_path': 'macosx64-minidump_stackwalk', 01:17:35 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/macosx64/releng.manifest', 01:17:35 INFO - 'opt_config_files': (), 01:17:35 INFO - 'pip_index': False, 01:17:35 INFO - 'postflight_run_cmd_suites': ({'architectures': ('32bit', '64bit'), 01:17:35 INFO - 'cmd': ('bash', 01:17:35 INFO - '-c', 01:17:35 INFO - 'screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'), 01:17:35 INFO - 'enabled': True, 01:17:35 INFO - 'halt_on_failure': False, 01:17:35 INFO - 'name': 'check_screen_resolution'},), 01:17:35 INFO - 'preflight_run_cmd_suites': ({'architectures': ('32bit', '64bit'), 01:17:35 INFO - 'cmd': ('bash', 01:17:35 INFO - '-c', 01:17:35 INFO - 'screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'), 01:17:35 INFO - 'enabled': True, 01:17:35 INFO - 'halt_on_failure': False, 01:17:35 INFO - 'name': 'check_screen_resolution'},), 01:17:35 INFO - 'python_webserver': False, 01:17:35 INFO - 'run_cmd_checks_enabled': True, 01:17:35 INFO - 'sps_profile': False, 01:17:35 INFO - 'sps_profile_interval': 0, 01:17:35 INFO - 'suite': 'other', 01:17:35 INFO - 'system_bits': '64', 01:17:35 INFO - 'talos_extra_options': ('--webServer', 'localhost'), 01:17:35 INFO - 'talos_url': 'https://hg.mozilla.org/build/talos/archive/tip.tar.gz', 01:17:35 INFO - 'tests': (), 01:17:35 INFO - 'title': 't-yosemite-r5-0025', 01:17:35 INFO - 'tooltool_cache': '/builds/tooltool_cache', 01:17:35 INFO - 'use_talos_json': True, 01:17:35 INFO - 'virtualenv_path': '/builds/slave/test/build/venv', 01:17:35 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 01:17:35 INFO - 'webroot': '/builds/slave/test/../talos-data', 01:17:35 INFO - 'work_dir': 'build'} 01:17:35 INFO - ##### 01:17:35 INFO - ##### Running clobber step. 01:17:35 INFO - ##### 01:17:35 INFO - Running pre-action listener: _resource_record_pre_action 01:17:35 INFO - Running main action method: clobber 01:17:35 INFO - rmtree: /builds/slave/test/build 01:17:35 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1 01:17:38 INFO - Running post-action listener: _resource_record_post_action 01:17:38 INFO - ##### 01:17:38 INFO - ##### Running read-buildbot-config step. 01:17:38 INFO - ##### 01:17:38 INFO - Running pre-action listener: _resource_record_pre_action 01:17:38 INFO - Running main action method: read_buildbot_config 01:17:38 INFO - Using buildbot properties: 01:17:38 INFO - { 01:17:38 INFO - "properties": { 01:17:38 INFO - "buildnumber": 97, 01:17:38 INFO - "product": "firefox", 01:17:38 INFO - "script_repo_revision": "production", 01:17:38 INFO - "builddir": "mozilla-aurora_yosemite_test-other", 01:17:38 INFO - "repository": "", 01:17:38 INFO - "buildername": "Rev5 MacOSX Yosemite 10.10 mozilla-aurora talos other", 01:17:38 INFO - "buildid": "20151029014646", 01:17:38 INFO - "slavename": "t-yosemite-r5-0025", 01:17:38 INFO - "pgo_build": "False", 01:17:38 INFO - "basedir": "/builds/slave/test", 01:17:38 INFO - "project": "", 01:17:38 INFO - "platform": "yosemite", 01:17:38 INFO - "master": "http://buildbot-master108.bb.releng.scl3.mozilla.com:8201/", 01:17:38 INFO - "slavebuilddir": "test", 01:17:38 INFO - "scheduler": "tests-mozilla-aurora-macosx64-talos", 01:17:38 INFO - "branch": "mozilla-aurora", 01:17:38 INFO - "repo_path": "releases/mozilla-aurora", 01:17:38 INFO - "stage_platform": "macosx64", 01:17:38 INFO - "builduid": "e2197d6fa76745edba8eadefeb37f684", 01:17:38 INFO - "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797" 01:17:38 INFO - }, 01:17:38 INFO - "sourcestamp": { 01:17:38 INFO - "repository": "", 01:17:38 INFO - "hasPatch": false, 01:17:38 INFO - "project": "", 01:17:38 INFO - "branch": "mozilla-aurora-macosx64-talos", 01:17:38 INFO - "changes": [ 01:17:38 INFO - { 01:17:38 INFO - "category": null, 01:17:38 INFO - "files": [ 01:17:38 INFO - { 01:17:38 INFO - "url": null, 01:17:38 INFO - "name": "https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.dmg" 01:17:38 INFO - } 01:17:38 INFO - ], 01:17:38 INFO - "repository": "", 01:17:38 INFO - "rev": "41fdefd640f368bccdeafe6446d42c0a5ad22797", 01:17:38 INFO - "who": "jyavenard@mozilla.com", 01:17:38 INFO - "when": 1446112210, 01:17:38 INFO - "number": 6592630, 01:17:38 INFO - "comments": "Bug 1218157: Only ever read from cached data in NotifyDataArrived. r=cpearce a=lizzard\n\nThe logic of queuing NotifyDataArrived and read data there was fundamentally flawed as we would continually perform reads from the same MediaResource at two different ends.\nThis would cause repetitive seeks and data being removed from the media cache. Worse, a read in NotifyDataArrived would cause another NotifyDataArrived to be scheduled.\n\nAs range-request are extremely slow, it would result in stutters and constant interruptions.\n", 01:17:38 INFO - "project": "", 01:17:38 INFO - "at": "Thu 29 Oct 2015 02:50:10", 01:17:38 INFO - "branch": "mozilla-aurora-macosx64-talos", 01:17:38 INFO - "revlink": "", 01:17:38 INFO - "properties": [ 01:17:38 INFO - [ 01:17:38 INFO - "buildid", 01:17:38 INFO - "20151029014646", 01:17:38 INFO - "Change" 01:17:38 INFO - ], 01:17:38 INFO - [ 01:17:38 INFO - "builduid", 01:17:38 INFO - "e2197d6fa76745edba8eadefeb37f684", 01:17:38 INFO - "Change" 01:17:38 INFO - ], 01:17:38 INFO - [ 01:17:38 INFO - "pgo_build", 01:17:38 INFO - "False", 01:17:38 INFO - "Change" 01:17:38 INFO - ] 01:17:38 INFO - ], 01:17:38 INFO - "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797" 01:17:38 INFO - } 01:17:38 INFO - ], 01:17:38 INFO - "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797" 01:17:38 INFO - } 01:17:38 INFO - } 01:17:38 INFO - Running post-action listener: _resource_record_post_action 01:17:38 INFO - ##### 01:17:38 INFO - ##### Running download-and-extract step. 01:17:38 INFO - ##### 01:17:38 INFO - Running pre-action listener: _resource_record_pre_action 01:17:38 INFO - Running main action method: download_and_extract 01:17:38 INFO - mkdir: /builds/slave/test/build/tests 01:17:38 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:17:38 INFO - https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/test_packages.json matches https://queue.taskcluster.net 01:17:38 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/test_packages.json 01:17:38 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/test_packages.json 01:17:38 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/test_packages.json to /builds/slave/test/build/test_packages.json 01:17:38 INFO - retry: Calling _download_file with args: ('http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/test_packages.json', '/builds/slave/test/build/test_packages.json'), kwargs: {}, attempt #1 01:17:39 INFO - Downloaded 1149 bytes. 01:17:39 INFO - Reading from file /builds/slave/test/build/test_packages.json 01:17:39 INFO - Using the following test package requirements: 01:17:39 INFO - {u'common': [u'firefox-43.0a2.en-US.mac.common.tests.zip'], 01:17:39 INFO - u'cppunittest': [u'firefox-43.0a2.en-US.mac.common.tests.zip', 01:17:39 INFO - u'firefox-43.0a2.en-US.mac.cppunittest.tests.zip'], 01:17:39 INFO - u'jittest': [u'firefox-43.0a2.en-US.mac.common.tests.zip', 01:17:39 INFO - u'jsshell-mac.zip'], 01:17:39 INFO - u'mochitest': [u'firefox-43.0a2.en-US.mac.common.tests.zip', 01:17:39 INFO - u'firefox-43.0a2.en-US.mac.mochitest.tests.zip'], 01:17:39 INFO - u'mozbase': [u'firefox-43.0a2.en-US.mac.common.tests.zip'], 01:17:39 INFO - u'reftest': [u'firefox-43.0a2.en-US.mac.common.tests.zip', 01:17:39 INFO - u'firefox-43.0a2.en-US.mac.reftest.tests.zip'], 01:17:39 INFO - u'talos': [u'firefox-43.0a2.en-US.mac.common.tests.zip', 01:17:39 INFO - u'firefox-43.0a2.en-US.mac.talos.tests.zip'], 01:17:39 INFO - u'web-platform': [u'firefox-43.0a2.en-US.mac.common.tests.zip', 01:17:39 INFO - u'firefox-43.0a2.en-US.mac.web-platform.tests.zip'], 01:17:39 INFO - u'webapprt': [u'firefox-43.0a2.en-US.mac.common.tests.zip'], 01:17:39 INFO - u'xpcshell': [u'firefox-43.0a2.en-US.mac.common.tests.zip', 01:17:39 INFO - u'firefox-43.0a2.en-US.mac.xpcshell.tests.zip']} 01:17:39 INFO - Downloading packages: [u'firefox-43.0a2.en-US.mac.common.tests.zip'] for test suite category: common 01:17:39 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:17:39 INFO - https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.common.tests.zip matches https://queue.taskcluster.net 01:17:39 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.common.tests.zip 01:17:39 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.common.tests.zip 01:17:39 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.common.tests.zip to /builds/slave/test/build/firefox-43.0a2.en-US.mac.common.tests.zip 01:17:39 INFO - retry: Calling _download_file with args: (u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.common.tests.zip', u'/builds/slave/test/build/firefox-43.0a2.en-US.mac.common.tests.zip'), kwargs: {}, attempt #1 01:17:41 INFO - Downloaded 18106185 bytes. 01:17:41 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-43.0a2.en-US.mac.common.tests.zip'] in /builds/slave/test/build/tests 01:17:41 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-43.0a2.en-US.mac.common.tests.zip 01:17:41 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-43.0a2.en-US.mac.common.tests.zip'] with output_timeout 1760 01:17:46 INFO - Return code: 0 01:17:46 INFO - Downloading packages: [u'firefox-43.0a2.en-US.mac.common.tests.zip', u'firefox-43.0a2.en-US.mac.talos.tests.zip'] for test suite category: talos 01:17:46 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:17:46 INFO - https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.common.tests.zip matches https://queue.taskcluster.net 01:17:46 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.common.tests.zip 01:17:46 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.common.tests.zip 01:17:46 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.common.tests.zip to /builds/slave/test/build/firefox-43.0a2.en-US.mac.common.tests.zip 01:17:46 INFO - retry: Calling _download_file with args: (u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.common.tests.zip', u'/builds/slave/test/build/firefox-43.0a2.en-US.mac.common.tests.zip'), kwargs: {}, attempt #1 01:17:53 INFO - Downloaded 18106185 bytes. 01:17:53 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-43.0a2.en-US.mac.common.tests.zip'] in /builds/slave/test/build/tests 01:17:53 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-43.0a2.en-US.mac.common.tests.zip 01:17:53 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-43.0a2.en-US.mac.common.tests.zip'] with output_timeout 1760 01:18:00 INFO - Return code: 0 01:18: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')]} 01:18:00 INFO - https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.talos.tests.zip matches https://queue.taskcluster.net 01:18:00 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.talos.tests.zip 01:18:00 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.talos.tests.zip 01:18:00 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.talos.tests.zip to /builds/slave/test/build/firefox-43.0a2.en-US.mac.talos.tests.zip 01:18:00 INFO - retry: Calling _download_file with args: (u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.talos.tests.zip', u'/builds/slave/test/build/firefox-43.0a2.en-US.mac.talos.tests.zip'), kwargs: {}, attempt #1 01:18:01 INFO - Downloaded 10881672 bytes. 01:18:01 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-43.0a2.en-US.mac.talos.tests.zip'] in /builds/slave/test/build/tests 01:18:01 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-43.0a2.en-US.mac.talos.tests.zip 01:18:01 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-43.0a2.en-US.mac.talos.tests.zip'] with output_timeout 1760 01:18:02 INFO - Return code: 0 01:18:02 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')]} 01:18:02 INFO - https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.dmg matches https://queue.taskcluster.net 01:18:02 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.dmg 01:18:02 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.dmg 01:18:02 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.dmg to /builds/slave/test/build/firefox-43.0a2.en-US.mac.dmg 01:18:02 INFO - retry: Calling _download_file with args: ('http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.dmg', '/builds/slave/test/build/firefox-43.0a2.en-US.mac.dmg'), kwargs: {}, attempt #1 01:18:06 INFO - Downloaded 106079073 bytes. 01:18:06 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.dmg 01:18:06 INFO - mkdir: /builds/slave/test/properties 01:18:06 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url 01:18:06 INFO - Writing to file /builds/slave/test/properties/build_url 01:18:06 INFO - Contents: 01:18:06 INFO - build_url:https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.dmg 01:18:06 INFO - Running post-action listener: _resource_record_post_action 01:18:06 INFO - Running post-action listener: _set_extra_try_arguments 01:18:06 INFO - ##### 01:18:06 INFO - ##### Running populate-webroot step. 01:18:06 INFO - ##### 01:18:06 INFO - Running pre-action listener: _resource_record_pre_action 01:18:06 INFO - Running main action method: populate_webroot 01:18:06 INFO - Populating webroot /builds/slave/test/../talos-data... 01:18:06 INFO - rmtree: /builds/slave/test/../talos-data/talos 01:18:06 INFO - retry: Calling rmtree with args: ('/builds/slave/test/../talos-data/talos',), kwargs: {}, attempt #1 01:18:06 INFO - copying tree: /builds/slave/test/build/tests/talos/talos to /builds/slave/test/../talos-data/talos 01:18:06 INFO - rmtree: /builds/slave/test/../talos-data/talos 01:18:06 INFO - Running post-action listener: _resource_record_post_action 01:18:06 INFO - ##### 01:18:06 INFO - ##### Running create-virtualenv step. 01:18:06 INFO - ##### 01:18:06 INFO - Running pre-action listener: _resource_record_pre_action 01:18:06 INFO - Running main action method: create_virtualenv 01:18:06 INFO - Creating virtualenv /builds/slave/test/build/venv 01:18:06 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 01:18:06 INFO - Copy/paste: /tools/buildbot/bin/python /tools/misc-python/virtualenv.py --no-site-packages --distribute /builds/slave/test/build/venv 01:18:07 INFO - The --no-site-packages flag is deprecated; it is now the default behavior. 01:18:07 INFO - Using real prefix '/tools/python27' 01:18:07 INFO - New python executable in /builds/slave/test/build/venv/bin/python 01:18:07 INFO - Installing distribute.............................................................................................................................................................................................done. 01:18:11 INFO - Installing pip.................done. 01:18:11 INFO - Return code: 0 01:18:11 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv 01:18:11 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:18:11 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 01:18:11 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:18:11 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:18:11 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 01:18:11 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:18:11 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 0x1048c1530>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1048a0180>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7ff82a631990>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1047f2920>, '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 0x104542e88>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10479ca58>, '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.GdR3T8lx2O/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.Xo8SBI494k/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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 01:18:11 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 01:18:11 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 01:18:11 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.GdR3T8lx2O/Render', 01:18:11 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 01:18:11 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 01:18:11 INFO - 'HOME': '/Users/cltbld', 01:18:11 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 01:18:11 INFO - 'LOGNAME': 'cltbld', 01:18:11 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 01:18:11 INFO - 'MOZ_NO_REMOTE': '1', 01:18:11 INFO - 'NO_EM_RESTART': '1', 01:18:11 INFO - 'PAGER': '/bin/cat', 01:18:11 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 01:18:11 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 01:18:11 INFO - 'PWD': '/builds/slave/test', 01:18:11 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 01:18:11 INFO - 'SHELL': '/bin/bash', 01:18:11 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.Xo8SBI494k/Listeners', 01:18:11 INFO - 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/', 01:18:11 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 01:18:11 INFO - 'USER': 'cltbld', 01:18:11 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 01:18:11 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 01:18:11 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 01:18:11 INFO - 'XPC_FLAGS': '0x0', 01:18:11 INFO - 'XPC_SERVICE_NAME': '0', 01:18:11 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'} 01:18:12 INFO - Ignoring indexes: https://pypi.python.org/simple/ 01:18:12 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 01:18:12 INFO - Cleaning up... 01:18:12 INFO - Return code: 0 01:18:12 INFO - Installing psutil>=0.7.1 into virtualenv /builds/slave/test/build/venv 01:18:12 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:18:12 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 01:18:12 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:18:12 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:18:12 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 01:18:12 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:18:12 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 0x1048c1530>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1048a0180>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7ff82a631990>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1047f2920>, '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 0x104542e88>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10479ca58>, '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.GdR3T8lx2O/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.Xo8SBI494k/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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 01:18:12 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 01:18:12 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 01:18:12 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.GdR3T8lx2O/Render', 01:18:12 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 01:18:12 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 01:18:12 INFO - 'HOME': '/Users/cltbld', 01:18:12 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 01:18:12 INFO - 'LOGNAME': 'cltbld', 01:18:12 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 01:18:12 INFO - 'MOZ_NO_REMOTE': '1', 01:18:12 INFO - 'NO_EM_RESTART': '1', 01:18:12 INFO - 'PAGER': '/bin/cat', 01:18:12 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 01:18:12 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 01:18:12 INFO - 'PWD': '/builds/slave/test', 01:18:12 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 01:18:12 INFO - 'SHELL': '/bin/bash', 01:18:12 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.Xo8SBI494k/Listeners', 01:18:12 INFO - 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/', 01:18:12 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 01:18:12 INFO - 'USER': 'cltbld', 01:18:12 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 01:18:12 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 01:18:12 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 01:18:12 INFO - 'XPC_FLAGS': '0x0', 01:18:12 INFO - 'XPC_SERVICE_NAME': '0', 01:18:12 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'} 01:18:12 INFO - Ignoring indexes: https://pypi.python.org/simple/ 01:18:12 INFO - Downloading/unpacking psutil>=0.7.1 01:18:12 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 01:18:12 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 01:18:12 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 01:18:12 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 01:18:12 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 01:18:12 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 01:18:14 INFO - Creating supposed download cache at /builds/slave/test/build/venv/cache 01:18:14 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fpsutil-3.1.1.tar.gz 01:18:14 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/psutil/setup.py) egg_info for package psutil 01:18:14 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 01:18:14 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 01:18:15 INFO - Installing collected packages: psutil 01:18:15 INFO - Running setup.py install for psutil 01:18:15 INFO - building 'psutil._psutil_osx' extension 01:18:15 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 01:18:17 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 01:18:17 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 01:18:17 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 01:18:17 INFO - building 'psutil._psutil_posix' extension 01:18:17 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 01:18:17 WARNING - psutil/_psutil_posix.c:403:11: warning: implicit declaration of function 'ioctl' is invalid in C99 [-Wimplicit-function-declaration] 01:18:17 INFO - ret = ioctl(sock, SIOCGIFFLAGS, &ifr); 01:18:17 INFO - ^ 01:18:17 INFO - 1 warning generated. 01:18:17 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 01:18:17 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 01:18:17 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 01:18:17 INFO - Successfully installed psutil 01:18:17 INFO - Cleaning up... 01:18:17 INFO - Return code: 0 01:18:17 INFO - Installing mozsystemmonitor==0.0.0 into virtualenv /builds/slave/test/build/venv 01:18:17 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:18:17 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 01:18:17 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:18:17 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:18:17 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 01:18:17 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:18:17 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '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 0x1048c1530>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1048a0180>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7ff82a631990>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1047f2920>, '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 0x104542e88>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10479ca58>, '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.GdR3T8lx2O/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.Xo8SBI494k/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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 01:18:17 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'mozsystemmonitor==0.0.0'] in /builds/slave/test/build 01:18:17 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub mozsystemmonitor==0.0.0 01:18:17 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.GdR3T8lx2O/Render', 01:18:17 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 01:18:17 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 01:18:17 INFO - 'HOME': '/Users/cltbld', 01:18:17 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 01:18:17 INFO - 'LOGNAME': 'cltbld', 01:18:17 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 01:18:17 INFO - 'MOZ_NO_REMOTE': '1', 01:18:17 INFO - 'NO_EM_RESTART': '1', 01:18:17 INFO - 'PAGER': '/bin/cat', 01:18:17 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 01:18:17 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 01:18:17 INFO - 'PWD': '/builds/slave/test', 01:18:17 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 01:18:17 INFO - 'SHELL': '/bin/bash', 01:18:17 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.Xo8SBI494k/Listeners', 01:18:17 INFO - 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/', 01:18:17 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 01:18:17 INFO - 'USER': 'cltbld', 01:18:17 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 01:18:17 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 01:18:17 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 01:18:17 INFO - 'XPC_FLAGS': '0x0', 01:18:17 INFO - 'XPC_SERVICE_NAME': '0', 01:18:17 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'} 01:18:18 INFO - Ignoring indexes: https://pypi.python.org/simple/ 01:18:18 INFO - Downloading/unpacking mozsystemmonitor==0.0.0 01:18:18 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 01:18:18 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 01:18:18 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 01:18:18 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 01:18:18 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 01:18:18 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 01:18:20 INFO - Downloading mozsystemmonitor-0.0.tar.gz 01:18:20 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fmozsystemmonitor-0.0.tar.gz 01:18:20 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/mozsystemmonitor/setup.py) egg_info for package mozsystemmonitor 01:18:20 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=0.7.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.0.0) 01:18:20 INFO - Installing collected packages: mozsystemmonitor 01:18:20 INFO - Running setup.py install for mozsystemmonitor 01:18:20 INFO - Successfully installed mozsystemmonitor 01:18:20 INFO - Cleaning up... 01:18:20 INFO - Return code: 0 01:18:20 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv 01:18:20 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:18:20 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 01:18:20 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:18:20 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:18:20 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 01:18:20 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:18:20 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '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 0x1048c1530>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1048a0180>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7ff82a631990>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1047f2920>, '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 0x104542e88>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10479ca58>, '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.GdR3T8lx2O/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.Xo8SBI494k/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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 01:18:20 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'blobuploader==1.2.4'] in /builds/slave/test/build 01:18:20 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub blobuploader==1.2.4 01:18:20 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.GdR3T8lx2O/Render', 01:18:20 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 01:18:20 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 01:18:20 INFO - 'HOME': '/Users/cltbld', 01:18:20 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 01:18:20 INFO - 'LOGNAME': 'cltbld', 01:18:20 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 01:18:20 INFO - 'MOZ_NO_REMOTE': '1', 01:18:20 INFO - 'NO_EM_RESTART': '1', 01:18:20 INFO - 'PAGER': '/bin/cat', 01:18:20 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 01:18:20 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 01:18:20 INFO - 'PWD': '/builds/slave/test', 01:18:20 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 01:18:20 INFO - 'SHELL': '/bin/bash', 01:18:20 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.Xo8SBI494k/Listeners', 01:18:20 INFO - 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/', 01:18:20 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 01:18:20 INFO - 'USER': 'cltbld', 01:18:20 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 01:18:20 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 01:18:20 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 01:18:20 INFO - 'XPC_FLAGS': '0x0', 01:18:20 INFO - 'XPC_SERVICE_NAME': '0', 01:18:20 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'} 01:18:21 INFO - Ignoring indexes: https://pypi.python.org/simple/ 01:18:21 INFO - Downloading/unpacking blobuploader==1.2.4 01:18:21 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 01:18:21 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 01:18:21 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 01:18:21 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 01:18:21 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 01:18:21 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 01:18:23 INFO - Downloading blobuploader-1.2.4.tar.gz 01:18:23 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fblobuploader-1.2.4.tar.gz 01:18:23 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blobuploader/setup.py) egg_info for package blobuploader 01:18:23 INFO - Downloading/unpacking requests==1.2.3. (from blobuploader==1.2.4) 01:18:23 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 01:18:23 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 01:18:23 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 01:18:23 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 01:18:23 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 01:18:23 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 01:18:24 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Frequests-1.2.3.tar.gz 01:18:24 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests 01:18:24 INFO - Downloading/unpacking docopt==0.6.1 (from blobuploader==1.2.4) 01:18:24 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 01:18:24 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 01:18:24 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 01:18:24 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 01:18:24 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 01:18:24 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 01:18:24 INFO - Downloading docopt-0.6.1.tar.gz 01:18:24 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fdocopt-0.6.1.tar.gz 01:18:24 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/docopt/setup.py) egg_info for package docopt 01:18:24 INFO - Installing collected packages: blobuploader, requests, docopt 01:18:24 INFO - Running setup.py install for blobuploader 01:18:24 INFO - changing mode of build/scripts-2.7/blobberc.py from 664 to 775 01:18:25 INFO - changing mode of /builds/slave/test/build/venv/bin/blobberc.py to 775 01:18:25 INFO - Running setup.py install for requests 01:18:25 INFO - Running setup.py install for docopt 01:18:25 INFO - Successfully installed blobuploader requests docopt 01:18:25 INFO - Cleaning up... 01:18:25 INFO - Return code: 0 01:18:25 INFO - Installing None into virtualenv /builds/slave/test/build/venv 01:18:25 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:18:25 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 01:18:25 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:18:25 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:18:25 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 01:18:25 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:18:25 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1048c1530>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1048a0180>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7ff82a631990>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1047f2920>, '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 0x104542e88>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10479ca58>, '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.GdR3T8lx2O/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.Xo8SBI494k/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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 01:18:25 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/config 01:18:25 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --no-deps --download-cache /builds/slave/test/build/venv/cache --timeout 120 -r /builds/slave/test/build/tests/config/mozbase_requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub 01:18:25 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.GdR3T8lx2O/Render', 01:18:25 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 01:18:25 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 01:18:25 INFO - 'HOME': '/Users/cltbld', 01:18:25 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 01:18:25 INFO - 'LOGNAME': 'cltbld', 01:18:25 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 01:18:25 INFO - 'MOZ_NO_REMOTE': '1', 01:18:25 INFO - 'NO_EM_RESTART': '1', 01:18:25 INFO - 'PAGER': '/bin/cat', 01:18:25 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 01:18:25 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 01:18:25 INFO - 'PWD': '/builds/slave/test', 01:18:25 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 01:18:25 INFO - 'SHELL': '/bin/bash', 01:18:25 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.Xo8SBI494k/Listeners', 01:18:25 INFO - 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/', 01:18:25 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 01:18:25 INFO - 'USER': 'cltbld', 01:18:25 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 01:18:25 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 01:18:25 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 01:18:25 INFO - 'XPC_FLAGS': '0x0', 01:18:25 INFO - 'XPC_SERVICE_NAME': '0', 01:18:25 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'} 01:18:26 INFO - Ignoring indexes: https://pypi.python.org/simple/ 01:18:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 01:18:26 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-Br_0wE-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 01:18:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 01:18:26 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-qFAhO0-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 01:18:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 01:18:26 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-Gfuw8q-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 01:18:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 01:18:26 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-uaqptv-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 01:18:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 01:18:26 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-ZfzLQC-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 01:18:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 01:18:26 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-fj6NOw-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 01:18:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 01:18:26 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-rxtxpQ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 01:18:26 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 01:18:26 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-anKpqG-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 01:18:27 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 01:18:27 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-303xvN-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 01:18:27 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 01:18:27 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-WBGm44-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 01:18:27 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 01:18:27 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-HJXegv-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 01:18:27 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 01:18:27 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-TGtNoP-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 01:18:27 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 01:18:27 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-QeCXQE-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 01:18:27 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 01:18:27 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-YAULeG-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 01:18:27 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 01:18:27 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-AQ2TRU-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 01:18:27 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 01:18:27 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-vNnZXj-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 01:18:28 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 01:18:28 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-ogn4CE-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 01:18:28 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion 01:18:28 INFO - Running setup.py install for manifestparser 01:18:28 INFO - Installing manifestparser script to /builds/slave/test/build/venv/bin 01:18:28 INFO - Running setup.py install for mozcrash 01:18:28 INFO - Running setup.py install for mozdebug 01:18:28 INFO - Running setup.py install for mozdevice 01:18:28 INFO - Installing sutini script to /builds/slave/test/build/venv/bin 01:18:28 INFO - Installing dm script to /builds/slave/test/build/venv/bin 01:18:28 INFO - Running setup.py install for mozfile 01:18:29 INFO - Running setup.py install for mozhttpd 01:18:29 INFO - Installing mozhttpd script to /builds/slave/test/build/venv/bin 01:18:29 INFO - Running setup.py install for mozinfo 01:18:29 INFO - Installing mozinfo script to /builds/slave/test/build/venv/bin 01:18:29 INFO - Running setup.py install for mozInstall 01:18:29 INFO - Installing moz_remove_from_system script to /builds/slave/test/build/venv/bin 01:18:29 INFO - Installing mozuninstall script to /builds/slave/test/build/venv/bin 01:18:29 INFO - Installing mozinstall script to /builds/slave/test/build/venv/bin 01:18:29 INFO - Installing moz_add_to_system script to /builds/slave/test/build/venv/bin 01:18:29 INFO - Running setup.py install for mozleak 01:18:29 INFO - Running setup.py install for mozlog 01:18:29 INFO - Installing structlog script to /builds/slave/test/build/venv/bin 01:18:29 INFO - Running setup.py install for moznetwork 01:18:30 INFO - Installing moznetwork script to /builds/slave/test/build/venv/bin 01:18:30 INFO - Running setup.py install for mozprocess 01:18:30 INFO - Running setup.py install for mozprofile 01:18:30 INFO - Installing mozprofile script to /builds/slave/test/build/venv/bin 01:18:30 INFO - Installing diff-profiles script to /builds/slave/test/build/venv/bin 01:18:30 INFO - Installing view-profile script to /builds/slave/test/build/venv/bin 01:18:30 INFO - Running setup.py install for mozrunner 01:18:30 INFO - Installing mozrunner script to /builds/slave/test/build/venv/bin 01:18:30 INFO - Running setup.py install for mozscreenshot 01:18:30 INFO - Running setup.py install for moztest 01:18:30 INFO - Running setup.py install for mozversion 01:18:31 INFO - Installing mozversion script to /builds/slave/test/build/venv/bin 01:18:31 INFO - Successfully installed manifestparser mozcrash mozdebug mozdevice mozfile mozhttpd mozinfo mozInstall mozleak mozlog moznetwork mozprocess mozprofile mozrunner mozscreenshot moztest mozversion 01:18:31 INFO - Cleaning up... 01:18:31 INFO - Return code: 0 01:18:31 INFO - Installing None into virtualenv /builds/slave/test/build/venv 01:18:31 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:18:31 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 01:18:31 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:18:31 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:18:31 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 01:18:31 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:18:31 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 0x1048c1530>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1048a0180>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7ff82a631990>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1047f2920>, '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 0x104542e88>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10479ca58>, '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.GdR3T8lx2O/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.Xo8SBI494k/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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 01:18:31 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 01:18:31 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 01:18:31 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.GdR3T8lx2O/Render', 01:18:31 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 01:18:31 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 01:18:31 INFO - 'HOME': '/Users/cltbld', 01:18:31 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 01:18:31 INFO - 'LOGNAME': 'cltbld', 01:18:31 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 01:18:31 INFO - 'MOZ_NO_REMOTE': '1', 01:18:31 INFO - 'NO_EM_RESTART': '1', 01:18:31 INFO - 'PAGER': '/bin/cat', 01:18:31 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 01:18:31 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 01:18:31 INFO - 'PWD': '/builds/slave/test', 01:18:31 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 01:18:31 INFO - 'SHELL': '/bin/bash', 01:18:31 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.Xo8SBI494k/Listeners', 01:18:31 INFO - 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/', 01:18:31 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 01:18:31 INFO - 'USER': 'cltbld', 01:18:31 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 01:18:31 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 01:18:31 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 01:18:31 INFO - 'XPC_FLAGS': '0x0', 01:18:31 INFO - 'XPC_SERVICE_NAME': '0', 01:18:31 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'} 01:18:31 INFO - Ignoring indexes: https://pypi.python.org/simple/ 01:18:31 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 01:18:31 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-AXrgc7-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 01:18:31 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)) 01:18:31 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 01:18:31 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-z706wU-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 01:18:31 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)) 01:18:31 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 01:18:31 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-56qKrC-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 01:18:31 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)) 01:18:31 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 01:18:31 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-gfVrTX-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 01:18:32 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)) 01:18:32 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 01:18:32 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-7H0gQe-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 01:18:32 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)) 01:18:32 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 01:18:32 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-1LvpBu-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 01:18:32 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)) 01:18:32 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 01:18:32 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-3RMobA-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 01:18:32 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)) 01:18:32 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 01:18:32 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-1D8rMD-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 01:18:32 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)) 01:18:32 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 01:18:32 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-DRrGAD-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 01:18:32 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)) 01:18:32 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 01:18:32 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-giQafB-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 01:18:32 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)) 01:18:32 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 01:18:32 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-mUOX2O-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 01:18:32 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)) 01:18:32 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 01:18:32 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-pojTyV-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 01:18:33 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)) 01:18:33 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 01:18:33 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-K7it1f-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 01:18:33 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)) 01:18:33 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 01:18:33 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-i2FnsM-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 01:18:33 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)) 01:18:33 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 01:18:33 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-2voBmn-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 01:18:33 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)) 01:18:33 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 01:18:33 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-UQuPw3-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 01:18:33 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)) 01:18:33 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 01:18:33 INFO - Running setup.py (path:/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/pip-8AkFgt-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 01:18:33 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)) 01:18:33 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)) 01:18:33 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)) 01:18:33 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)) 01:18:33 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)) 01:18:33 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)) 01:18:33 INFO - Downloading/unpacking blessings>=1.3 (from mozlog==3.0->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 01:18:33 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 01:18:33 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 01:18:33 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 01:18:33 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 01:18:33 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 01:18:33 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 01:18:36 INFO - Downloading blessings-1.5.1.tar.gz 01:18:36 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 01:18:36 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blessings/setup.py) egg_info for package blessings 01:18:36 INFO - Installing collected packages: blessings 01:18:36 INFO - Running setup.py install for blessings 01:18:36 INFO - Successfully installed blessings 01:18:36 INFO - Cleaning up... 01:18:36 INFO - Return code: 0 01:18:36 INFO - Done creating virtualenv /builds/slave/test/build/venv. 01:18:36 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 01:18:36 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 01:18:36 INFO - Reading from file tmpfile_stdout 01:18:36 INFO - Current package versions: 01:18:36 INFO - blessings == 1.5.1 01:18:36 INFO - blobuploader == 1.2.4 01:18:36 INFO - docopt == 0.6.1 01:18:36 INFO - manifestparser == 1.1 01:18:36 INFO - mozInstall == 1.12 01:18:36 INFO - mozcrash == 0.16 01:18:36 INFO - mozdebug == 0.1 01:18:36 INFO - mozdevice == 0.46 01:18:36 INFO - mozfile == 1.2 01:18:36 INFO - mozhttpd == 0.7 01:18:36 INFO - mozinfo == 0.8 01:18:36 INFO - mozleak == 0.1 01:18:36 INFO - mozlog == 3.0 01:18:36 INFO - moznetwork == 0.27 01:18:36 INFO - mozprocess == 0.22 01:18:36 INFO - mozprofile == 0.27 01:18:36 INFO - mozrunner == 6.10 01:18:36 INFO - mozscreenshot == 0.1 01:18:36 INFO - mozsystemmonitor == 0.0 01:18:36 INFO - moztest == 0.7 01:18:36 INFO - mozversion == 1.4 01:18:36 INFO - psutil == 3.1.1 01:18:36 INFO - requests == 1.2.3 01:18:36 INFO - wsgiref == 0.1.2 01:18:36 INFO - Installing None into virtualenv /builds/slave/test/build/venv 01:18:36 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:18:36 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 01:18:36 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:18:36 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:18:36 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 01:18:36 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:18:36 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 0x1048c1530>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1048a0180>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7ff82a631990>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1047f2920>, '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 0x104542e88>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10479ca58>, '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.GdR3T8lx2O/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.Xo8SBI494k/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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 01:18:36 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 01:18:36 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 01:18:36 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.GdR3T8lx2O/Render', 01:18:36 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 01:18:36 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 01:18:36 INFO - 'HOME': '/Users/cltbld', 01:18:36 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 01:18:36 INFO - 'LOGNAME': 'cltbld', 01:18:36 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 01:18:36 INFO - 'MOZ_NO_REMOTE': '1', 01:18:36 INFO - 'NO_EM_RESTART': '1', 01:18:36 INFO - 'PAGER': '/bin/cat', 01:18:36 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 01:18:36 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 01:18:36 INFO - 'PWD': '/builds/slave/test', 01:18:36 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 01:18:36 INFO - 'SHELL': '/bin/bash', 01:18:36 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.Xo8SBI494k/Listeners', 01:18:36 INFO - 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/', 01:18:36 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 01:18:36 INFO - 'USER': 'cltbld', 01:18:36 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 01:18:36 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 01:18:36 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 01:18:36 INFO - 'XPC_FLAGS': '0x0', 01:18:36 INFO - 'XPC_SERVICE_NAME': '0', 01:18:36 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'} 01:18:37 INFO - Ignoring indexes: https://pypi.python.org/simple/ 01:18:37 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)) 01:18:37 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)) 01:18:37 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)) 01:18:37 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)) 01:18:37 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)) 01:18:37 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)) 01:18:37 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)) 01:18:37 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)) 01:18:37 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)) 01:18:37 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)) 01:18:37 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)) 01:18:37 INFO - Cleaning up... 01:18:37 INFO - Return code: 0 01:18:37 INFO - Running post-action listener: _resource_record_post_action 01:18:37 INFO - Running post-action listener: _start_resource_monitoring 01:18:37 INFO - Starting resource monitoring. 01:18:37 INFO - ##### 01:18:37 INFO - ##### Running install step. 01:18:37 INFO - ##### 01:18:37 INFO - Running pre-action listener: _resource_record_pre_action 01:18:37 INFO - Running main action method: install 01:18:37 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 01:18:37 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 01:18:37 INFO - Reading from file tmpfile_stdout 01:18:37 INFO - Detecting whether we're running mozinstall >=1.0... 01:18:37 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h'] 01:18:37 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h 01:18:37 INFO - Reading from file tmpfile_stdout 01:18:37 INFO - Output received: 01:18:37 INFO - Usage: mozinstall [options] installer 01:18:37 INFO - Options: 01:18:37 INFO - -h, --help show this help message and exit 01:18:37 INFO - -d DEST, --destination=DEST 01:18:37 INFO - Directory to install application into. [default: 01:18:37 INFO - "/builds/slave/test"] 01:18:37 INFO - --app=APP Application being installed. [default: firefox] 01:18:37 INFO - mkdir: /builds/slave/test/build/application 01:18:37 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '/builds/slave/test/build/firefox-43.0a2.en-US.mac.dmg', '--destination', '/builds/slave/test/build/application'] 01:18:37 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall /builds/slave/test/build/firefox-43.0a2.en-US.mac.dmg --destination /builds/slave/test/build/application 01:19:15 INFO - Reading from file tmpfile_stdout 01:19:15 INFO - Output received: 01:19:15 INFO - /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox 01:19:15 INFO - Running post-action listener: _resource_record_post_action 01:19:15 INFO - ##### 01:19:15 INFO - ##### Running run-tests step. 01:19:15 INFO - ##### 01:19:15 INFO - Running pre-action listener: _resource_record_pre_action 01:19:15 INFO - Running main action method: run_tests 01:19:15 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version'] 01:19:15 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version 01:19:15 INFO - Python 2.7.3 01:19:15 INFO - Return code: 0 01:19:15 INFO - grabbing minidump binary from tooltool 01:19:15 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:19:15 INFO - retry: Calling run_command with args: (['/tools/tooltool.py', '--url', 'https://api.pub.build.mozilla.org/tooltool/', '--authentication-file', '/builds/relengapi.tok', 'fetch', '-m', '/builds/slave/test/build/tests/config/tooltool-manifests/macosx64/releng.manifest', '-o', '-c', '/builds/tooltool_cache'],), kwargs: {'error_list': [{'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1047f2920>, '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 0x104542e88>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10479ca58>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1 01:19:15 INFO - Running command: ['/tools/tooltool.py', '--url', 'https://api.pub.build.mozilla.org/tooltool/', '--authentication-file', '/builds/relengapi.tok', 'fetch', '-m', '/builds/slave/test/build/tests/config/tooltool-manifests/macosx64/releng.manifest', '-o', '-c', '/builds/tooltool_cache'] in /builds/slave/test/build 01:19:15 INFO - Copy/paste: /tools/tooltool.py --url https://api.pub.build.mozilla.org/tooltool/ --authentication-file /builds/relengapi.tok fetch -m /builds/slave/test/build/tests/config/tooltool-manifests/macosx64/releng.manifest -o -c /builds/tooltool_cache 01:19:15 INFO - INFO - File macosx64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache 01:19:15 INFO - Return code: 0 01:19:15 INFO - Chmoding /builds/slave/test/build/macosx64-minidump_stackwalk to 0755 01:19:15 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir 01:19:15 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir 01:19:15 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/macosx64-minidump_stackwalk 01:19:15 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir 01:19:15 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--debug', '--branchName', 'Mozilla-Aurora', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.crashreporter-symbols.zip', '--activeTests', 'a11yr:ts_paint:tpaint:sessionrestore:sessionrestore_no_auto_restore', '--executablePath', '/builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox', '--title', 't-yosemite-r5-0025', '--webServer', 'localhost'] in /builds/slave/test/build 01:19:15 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/tests/talos/talos/run_tests.py --debug --branchName Mozilla-Aurora --symbolsPath https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.crashreporter-symbols.zip --activeTests a11yr:ts_paint:tpaint:sessionrestore:sessionrestore_no_auto_restore --executablePath /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox --title t-yosemite-r5-0025 --webServer localhost 01:19:15 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.GdR3T8lx2O/Render', 01:19:15 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 01:19:15 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 01:19:15 INFO - 'HOME': '/Users/cltbld', 01:19:15 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 01:19:15 INFO - 'LOGNAME': 'cltbld', 01:19:15 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 01:19:15 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/macosx64-minidump_stackwalk', 01:19:15 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 01:19:15 INFO - 'MOZ_NO_REMOTE': '1', 01:19:15 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 01:19:15 INFO - 'NO_EM_RESTART': '1', 01:19:15 INFO - 'PAGER': '/bin/cat', 01:19:15 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 01:19:15 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 01:19:15 INFO - 'PWD': '/builds/slave/test', 01:19:15 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 01:19:15 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 01:19:15 INFO - 'SHELL': '/bin/bash', 01:19:15 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.Xo8SBI494k/Listeners', 01:19:15 INFO - 'TMPDIR': '/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/', 01:19:15 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 01:19:15 INFO - 'USER': 'cltbld', 01:19:15 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 01:19:15 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 01:19:15 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 01:19:15 INFO - 'XPC_FLAGS': '0x0', 01:19:15 INFO - 'XPC_SERVICE_NAME': '0', 01:19:15 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0x0:0x0'} 01:19:15 INFO - Calling ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--debug', '--branchName', 'Mozilla-Aurora', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.crashreporter-symbols.zip', '--activeTests', 'a11yr:ts_paint:tpaint:sessionrestore:sessionrestore_no_auto_restore', '--executablePath', '/builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox', '--title', 't-yosemite-r5-0025', '--webServer', 'localhost'] with output_timeout 3600 01:19:16 INFO - mozversion INFO | application_buildid: 20151029014646 01:19:16 INFO - mozversion INFO | application_changeset: 41fdefd640f368bccdeafe6446d42c0a5ad22797 01:19:16 INFO - mozversion INFO | application_display_name: FirefoxDeveloperEdition 01:19:16 INFO - mozversion INFO | application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384} 01:19:16 INFO - mozversion INFO | application_name: Firefox 01:19:16 INFO - mozversion INFO | application_remotingname: firefox-dev 01:19:16 INFO - mozversion INFO | application_repository: https://hg.mozilla.org/releases/mozilla-aurora 01:19:16 INFO - mozversion INFO | application_vendor: Mozilla 01:19:16 INFO - mozversion INFO | application_version: 43.0a2 01:19:16 INFO - mozversion INFO | platform_buildid: 20151029014646 01:19:16 INFO - mozversion INFO | platform_changeset: 41fdefd640f368bccdeafe6446d42c0a5ad22797 01:19:16 INFO - mozversion INFO | platform_repository: https://hg.mozilla.org/releases/mozilla-aurora 01:19:16 INFO - mozversion INFO | platform_version: 43.0a2 01:19:16 INFO - 2015-10-30 01:19:16,148 DEBUG : using testdate: 1446193156 01:19:16 INFO - 2015-10-30 01:19:16,148 DEBUG : actual date: 1446193156 01:19:16 INFO - 2015-10-30 01:19:16,209 INFO : Starting test suite t-yosemite-r5-0025 01:19:16 INFO - 2015-10-30 01:19:16,209 INFO : Starting test a11yr 01:19:16 INFO - 2015-10-30 01:19:16,209 DEBUG : operating with platform_type : mac_ 01:19:16 INFO - 2015-10-30 01:19:16,210 INFO : Initialising browser for a11yr test... 01:19:16 INFO - 2015-10-30 01:19:16,244 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpbxOdYQ/profile http://localhost/getInfo.html 01:19:19 INFO - 2015-10-30 01:19:19,865 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 01:19:19 INFO - 2015-10-30 01:19:19,865 DEBUG : BROWSER_OUTPUT: colorDepth:24 01:19:19 INFO - 2015-10-30 01:19:19,866 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/689 01:19:19 INFO - 2015-10-30 01:19:19,866 DEBUG : BROWSER_OUTPUT: __metrics 01:19:19 INFO - 2015-10-30 01:19:19,884 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 01:19:20 INFO - 2015-10-30 01:19:20,491 INFO : Browser initialized. 01:19:20 INFO - 2015-10-30 01:19:20,491 INFO : Running cycle 1/1 for a11yr test... 01:19:20 INFO - 2015-10-30 01:19:20,492 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpbxOdYQ/profile -tp file:/builds/slave/test/build/tests/talos/talos/page_load_test/a11y/a11y.manifest -tpchrome -tpmozafterpaint -tpnoisy -tpcycles 1 -tppagecycles 25 01:19:32 INFO - 2015-10-30 01:19:32,458 DEBUG : BROWSER_OUTPUT: RSS: Main: 195084288 01:19:32 INFO - 2015-10-30 01:19:32,458 DEBUG : BROWSER_OUTPUT: 01:19:33 INFO - 2015-10-30 01:19:33,564 DEBUG : BROWSER_OUTPUT: Cycle 1(1): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:19:34 INFO - 2015-10-30 01:19:34,175 DEBUG : BROWSER_OUTPUT: RSS: Main: 245010432 01:19:34 INFO - 2015-10-30 01:19:34,175 DEBUG : BROWSER_OUTPUT: 01:19:35 INFO - 2015-10-30 01:19:35,449 DEBUG : BROWSER_OUTPUT: Cycle 1(2): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:19:36 INFO - 2015-10-30 01:19:36,119 DEBUG : BROWSER_OUTPUT: RSS: Main: 260526080 01:19:36 INFO - 2015-10-30 01:19:36,120 DEBUG : BROWSER_OUTPUT: 01:19:37 INFO - 2015-10-30 01:19:37,398 DEBUG : BROWSER_OUTPUT: Cycle 1(3): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:19:38 INFO - 2015-10-30 01:19:38,063 DEBUG : BROWSER_OUTPUT: RSS: Main: 260419584 01:19:38 INFO - 2015-10-30 01:19:38,063 DEBUG : BROWSER_OUTPUT: 01:19:39 INFO - 2015-10-30 01:19:39,362 DEBUG : BROWSER_OUTPUT: Cycle 1(4): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:19:40 INFO - 2015-10-30 01:19:40,032 DEBUG : BROWSER_OUTPUT: RSS: Main: 261636096 01:19:40 INFO - 2015-10-30 01:19:40,032 DEBUG : BROWSER_OUTPUT: 01:19:41 INFO - 2015-10-30 01:19:41,318 DEBUG : BROWSER_OUTPUT: Cycle 1(5): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:19:41 INFO - 2015-10-30 01:19:41,995 DEBUG : BROWSER_OUTPUT: RSS: Main: 263385088 01:19:41 INFO - 2015-10-30 01:19:41,995 DEBUG : BROWSER_OUTPUT: 01:19:43 INFO - 2015-10-30 01:19:43,303 DEBUG : BROWSER_OUTPUT: Cycle 1(6): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:19:43 INFO - 2015-10-30 01:19:43,980 DEBUG : BROWSER_OUTPUT: RSS: Main: 264544256 01:19:43 INFO - 2015-10-30 01:19:43,981 DEBUG : BROWSER_OUTPUT: 01:19:45 INFO - 2015-10-30 01:19:45,290 DEBUG : BROWSER_OUTPUT: Cycle 1(7): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:19:45 INFO - 2015-10-30 01:19:45,974 DEBUG : BROWSER_OUTPUT: RSS: Main: 264585216 01:19:45 INFO - 2015-10-30 01:19:45,974 DEBUG : BROWSER_OUTPUT: 01:19:47 INFO - 2015-10-30 01:19:47,310 DEBUG : BROWSER_OUTPUT: Cycle 1(8): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:19:47 INFO - 2015-10-30 01:19:47,981 DEBUG : BROWSER_OUTPUT: RSS: Main: 265367552 01:19:47 INFO - 2015-10-30 01:19:47,982 DEBUG : BROWSER_OUTPUT: 01:19:49 INFO - 2015-10-30 01:19:49,296 DEBUG : BROWSER_OUTPUT: Cycle 1(9): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:19:49 INFO - 2015-10-30 01:19:49,968 DEBUG : BROWSER_OUTPUT: RSS: Main: 264306688 01:19:49 INFO - 2015-10-30 01:19:49,968 DEBUG : BROWSER_OUTPUT: 01:19:51 INFO - 2015-10-30 01:19:51,247 DEBUG : BROWSER_OUTPUT: Cycle 1(10): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:19:51 INFO - 2015-10-30 01:19:51,921 DEBUG : BROWSER_OUTPUT: RSS: Main: 265670656 01:19:51 INFO - 2015-10-30 01:19:51,921 DEBUG : BROWSER_OUTPUT: 01:19:53 INFO - 2015-10-30 01:19:53,112 DEBUG : BROWSER_OUTPUT: Cycle 1(11): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:19:53 INFO - 2015-10-30 01:19:53,794 DEBUG : BROWSER_OUTPUT: RSS: Main: 264298496 01:19:53 INFO - 2015-10-30 01:19:53,794 DEBUG : BROWSER_OUTPUT: 01:19:55 INFO - 2015-10-30 01:19:55,087 DEBUG : BROWSER_OUTPUT: Cycle 1(12): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:19:55 INFO - 2015-10-30 01:19:55,773 DEBUG : BROWSER_OUTPUT: RSS: Main: 265449472 01:19:55 INFO - 2015-10-30 01:19:55,773 DEBUG : BROWSER_OUTPUT: 01:19:57 INFO - 2015-10-30 01:19:57,107 DEBUG : BROWSER_OUTPUT: Cycle 1(13): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:19:57 INFO - 2015-10-30 01:19:57,785 DEBUG : BROWSER_OUTPUT: RSS: Main: 265805824 01:19:57 INFO - 2015-10-30 01:19:57,785 DEBUG : BROWSER_OUTPUT: 01:19:59 INFO - 2015-10-30 01:19:59,053 DEBUG : BROWSER_OUTPUT: Cycle 1(14): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:19:59 INFO - 2015-10-30 01:19:59,729 DEBUG : BROWSER_OUTPUT: RSS: Main: 267010048 01:19:59 INFO - 2015-10-30 01:19:59,729 DEBUG : BROWSER_OUTPUT: 01:20:00 INFO - 2015-10-30 01:20:00,941 DEBUG : BROWSER_OUTPUT: Cycle 1(15): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:01 INFO - 2015-10-30 01:20:01,628 DEBUG : BROWSER_OUTPUT: RSS: Main: 265338880 01:20:01 INFO - 2015-10-30 01:20:01,628 DEBUG : BROWSER_OUTPUT: 01:20:02 INFO - 2015-10-30 01:20:02,838 DEBUG : BROWSER_OUTPUT: Cycle 1(16): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:03 INFO - 2015-10-30 01:20:03,514 DEBUG : BROWSER_OUTPUT: RSS: Main: 266481664 01:20:03 INFO - 2015-10-30 01:20:03,515 DEBUG : BROWSER_OUTPUT: 01:20:04 INFO - 2015-10-30 01:20:04,678 DEBUG : BROWSER_OUTPUT: Cycle 1(17): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:05 INFO - 2015-10-30 01:20:05,369 DEBUG : BROWSER_OUTPUT: RSS: Main: 264957952 01:20:05 INFO - 2015-10-30 01:20:05,369 DEBUG : BROWSER_OUTPUT: 01:20:06 INFO - 2015-10-30 01:20:06,640 DEBUG : BROWSER_OUTPUT: Cycle 1(18): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:07 INFO - 2015-10-30 01:20:07,326 DEBUG : BROWSER_OUTPUT: RSS: Main: 265977856 01:20:07 INFO - 2015-10-30 01:20:07,326 DEBUG : BROWSER_OUTPUT: 01:20:08 INFO - 2015-10-30 01:20:08,593 DEBUG : BROWSER_OUTPUT: Cycle 1(19): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:09 INFO - 2015-10-30 01:20:09,270 DEBUG : BROWSER_OUTPUT: RSS: Main: 265375744 01:20:09 INFO - 2015-10-30 01:20:09,270 DEBUG : BROWSER_OUTPUT: 01:20:10 INFO - 2015-10-30 01:20:10,596 DEBUG : BROWSER_OUTPUT: Cycle 1(20): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:11 INFO - 2015-10-30 01:20:11,276 DEBUG : BROWSER_OUTPUT: RSS: Main: 267128832 01:20:11 INFO - 2015-10-30 01:20:11,276 DEBUG : BROWSER_OUTPUT: 01:20:12 INFO - 2015-10-30 01:20:12,572 DEBUG : BROWSER_OUTPUT: Cycle 1(21): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:13 INFO - 2015-10-30 01:20:13,258 DEBUG : BROWSER_OUTPUT: RSS: Main: 266661888 01:20:13 INFO - 2015-10-30 01:20:13,258 DEBUG : BROWSER_OUTPUT: 01:20:14 INFO - 2015-10-30 01:20:14,472 DEBUG : BROWSER_OUTPUT: Cycle 1(22): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:15 INFO - 2015-10-30 01:20:15,159 DEBUG : BROWSER_OUTPUT: RSS: Main: 266252288 01:20:15 INFO - 2015-10-30 01:20:15,159 DEBUG : BROWSER_OUTPUT: 01:20:16 INFO - 2015-10-30 01:20:16,414 DEBUG : BROWSER_OUTPUT: Cycle 1(23): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:17 INFO - 2015-10-30 01:20:17,093 DEBUG : BROWSER_OUTPUT: RSS: Main: 267026432 01:20:17 INFO - 2015-10-30 01:20:17,094 DEBUG : BROWSER_OUTPUT: 01:20:18 INFO - 2015-10-30 01:20:18,380 DEBUG : BROWSER_OUTPUT: Cycle 1(24): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:19 INFO - 2015-10-30 01:20:19,068 DEBUG : BROWSER_OUTPUT: RSS: Main: 267440128 01:20:19 INFO - 2015-10-30 01:20:19,068 DEBUG : BROWSER_OUTPUT: 01:20:20 INFO - 2015-10-30 01:20:20,351 DEBUG : BROWSER_OUTPUT: Cycle 1(25): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:21 INFO - 2015-10-30 01:20:21,029 DEBUG : BROWSER_OUTPUT: RSS: Main: 272949248 01:20:21 INFO - 2015-10-30 01:20:21,030 DEBUG : BROWSER_OUTPUT: 01:20:21 INFO - 2015-10-30 01:20:21,816 DEBUG : BROWSER_OUTPUT: Cycle 1(1): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:22 INFO - 2015-10-30 01:20:22,400 DEBUG : BROWSER_OUTPUT: RSS: Main: 270348288 01:20:22 INFO - 2015-10-30 01:20:22,400 DEBUG : BROWSER_OUTPUT: 01:20:23 INFO - 2015-10-30 01:20:23,126 DEBUG : BROWSER_OUTPUT: Cycle 1(2): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:23 INFO - 2015-10-30 01:20:23,753 DEBUG : BROWSER_OUTPUT: RSS: Main: 276086784 01:20:23 INFO - 2015-10-30 01:20:23,753 DEBUG : BROWSER_OUTPUT: 01:20:24 INFO - 2015-10-30 01:20:24,486 DEBUG : BROWSER_OUTPUT: Cycle 1(3): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:25 INFO - 2015-10-30 01:20:25,080 DEBUG : BROWSER_OUTPUT: RSS: Main: 275271680 01:20:25 INFO - 2015-10-30 01:20:25,080 DEBUG : BROWSER_OUTPUT: 01:20:25 INFO - 2015-10-30 01:20:25,831 DEBUG : BROWSER_OUTPUT: Cycle 1(4): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:26 INFO - 2015-10-30 01:20:26,426 DEBUG : BROWSER_OUTPUT: RSS: Main: 275644416 01:20:26 INFO - 2015-10-30 01:20:26,426 DEBUG : BROWSER_OUTPUT: 01:20:27 INFO - 2015-10-30 01:20:27,114 DEBUG : BROWSER_OUTPUT: Cycle 1(5): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:27 INFO - 2015-10-30 01:20:27,710 DEBUG : BROWSER_OUTPUT: RSS: Main: 275419136 01:20:27 INFO - 2015-10-30 01:20:27,710 DEBUG : BROWSER_OUTPUT: 01:20:28 INFO - 2015-10-30 01:20:28,409 DEBUG : BROWSER_OUTPUT: Cycle 1(6): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:29 INFO - 2015-10-30 01:20:29,001 DEBUG : BROWSER_OUTPUT: RSS: Main: 275460096 01:20:29 INFO - 2015-10-30 01:20:29,001 DEBUG : BROWSER_OUTPUT: 01:20:29 INFO - 2015-10-30 01:20:29,732 DEBUG : BROWSER_OUTPUT: Cycle 1(7): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:30 INFO - 2015-10-30 01:20:30,330 DEBUG : BROWSER_OUTPUT: RSS: Main: 275443712 01:20:30 INFO - 2015-10-30 01:20:30,330 DEBUG : BROWSER_OUTPUT: 01:20:31 INFO - 2015-10-30 01:20:31,053 DEBUG : BROWSER_OUTPUT: Cycle 1(8): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:31 INFO - 2015-10-30 01:20:31,656 DEBUG : BROWSER_OUTPUT: RSS: Main: 274997248 01:20:31 INFO - 2015-10-30 01:20:31,656 DEBUG : BROWSER_OUTPUT: 01:20:32 INFO - 2015-10-30 01:20:32,377 DEBUG : BROWSER_OUTPUT: Cycle 1(9): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:32 INFO - 2015-10-30 01:20:32,973 DEBUG : BROWSER_OUTPUT: RSS: Main: 274767872 01:20:32 INFO - 2015-10-30 01:20:32,974 DEBUG : BROWSER_OUTPUT: 01:20:33 INFO - 2015-10-30 01:20:33,660 DEBUG : BROWSER_OUTPUT: Cycle 1(10): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:34 INFO - 2015-10-30 01:20:34,268 DEBUG : BROWSER_OUTPUT: RSS: Main: 270028800 01:20:34 INFO - 2015-10-30 01:20:34,268 DEBUG : BROWSER_OUTPUT: 01:20:34 INFO - 2015-10-30 01:20:34,991 DEBUG : BROWSER_OUTPUT: Cycle 1(11): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:35 INFO - 2015-10-30 01:20:35,583 DEBUG : BROWSER_OUTPUT: RSS: Main: 269664256 01:20:35 INFO - 2015-10-30 01:20:35,584 DEBUG : BROWSER_OUTPUT: 01:20:36 INFO - 2015-10-30 01:20:36,313 DEBUG : BROWSER_OUTPUT: Cycle 1(12): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:36 INFO - 2015-10-30 01:20:36,908 DEBUG : BROWSER_OUTPUT: RSS: Main: 270516224 01:20:36 INFO - 2015-10-30 01:20:36,909 DEBUG : BROWSER_OUTPUT: 01:20:37 INFO - 2015-10-30 01:20:37,601 DEBUG : BROWSER_OUTPUT: Cycle 1(13): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:38 INFO - 2015-10-30 01:20:38,201 DEBUG : BROWSER_OUTPUT: RSS: Main: 270544896 01:20:38 INFO - 2015-10-30 01:20:38,201 DEBUG : BROWSER_OUTPUT: 01:20:38 INFO - 2015-10-30 01:20:38,925 DEBUG : BROWSER_OUTPUT: Cycle 1(14): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:39 INFO - 2015-10-30 01:20:39,525 DEBUG : BROWSER_OUTPUT: RSS: Main: 270614528 01:20:39 INFO - 2015-10-30 01:20:39,525 DEBUG : BROWSER_OUTPUT: 01:20:40 INFO - 2015-10-30 01:20:40,248 DEBUG : BROWSER_OUTPUT: Cycle 1(15): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:40 INFO - 2015-10-30 01:20:40,848 DEBUG : BROWSER_OUTPUT: RSS: Main: 270327808 01:20:40 INFO - 2015-10-30 01:20:40,848 DEBUG : BROWSER_OUTPUT: 01:20:41 INFO - 2015-10-30 01:20:41,554 DEBUG : BROWSER_OUTPUT: Cycle 1(16): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:42 INFO - 2015-10-30 01:20:42,156 DEBUG : BROWSER_OUTPUT: RSS: Main: 270606336 01:20:42 INFO - 2015-10-30 01:20:42,156 DEBUG : BROWSER_OUTPUT: 01:20:42 INFO - 2015-10-30 01:20:42,879 DEBUG : BROWSER_OUTPUT: Cycle 1(17): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:43 INFO - 2015-10-30 01:20:43,481 DEBUG : BROWSER_OUTPUT: RSS: Main: 269565952 01:20:43 INFO - 2015-10-30 01:20:43,481 DEBUG : BROWSER_OUTPUT: 01:20:44 INFO - 2015-10-30 01:20:44,205 DEBUG : BROWSER_OUTPUT: Cycle 1(18): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:44 INFO - 2015-10-30 01:20:44,808 DEBUG : BROWSER_OUTPUT: RSS: Main: 269316096 01:20:44 INFO - 2015-10-30 01:20:44,808 DEBUG : BROWSER_OUTPUT: 01:20:45 INFO - 2015-10-30 01:20:45,528 DEBUG : BROWSER_OUTPUT: Cycle 1(19): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:46 INFO - 2015-10-30 01:20:46,133 DEBUG : BROWSER_OUTPUT: RSS: Main: 269316096 01:20:46 INFO - 2015-10-30 01:20:46,133 DEBUG : BROWSER_OUTPUT: 01:20:46 INFO - 2015-10-30 01:20:46,858 DEBUG : BROWSER_OUTPUT: Cycle 1(20): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:47 INFO - 2015-10-30 01:20:47,453 DEBUG : BROWSER_OUTPUT: RSS: Main: 269172736 01:20:47 INFO - 2015-10-30 01:20:47,453 DEBUG : BROWSER_OUTPUT: 01:20:48 INFO - 2015-10-30 01:20:48,155 DEBUG : BROWSER_OUTPUT: Cycle 1(21): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:48 INFO - 2015-10-30 01:20:48,757 DEBUG : BROWSER_OUTPUT: RSS: Main: 268025856 01:20:48 INFO - 2015-10-30 01:20:48,758 DEBUG : BROWSER_OUTPUT: 01:20:49 INFO - 2015-10-30 01:20:49,468 DEBUG : BROWSER_OUTPUT: Cycle 1(22): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:50 INFO - 2015-10-30 01:20:50,071 DEBUG : BROWSER_OUTPUT: RSS: Main: 269193216 01:20:50 INFO - 2015-10-30 01:20:50,071 DEBUG : BROWSER_OUTPUT: 01:20:50 INFO - 2015-10-30 01:20:50,759 DEBUG : BROWSER_OUTPUT: Cycle 1(23): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:51 INFO - 2015-10-30 01:20:51,350 DEBUG : BROWSER_OUTPUT: RSS: Main: 269381632 01:20:51 INFO - 2015-10-30 01:20:51,350 DEBUG : BROWSER_OUTPUT: 01:20:52 INFO - 2015-10-30 01:20:52,079 DEBUG : BROWSER_OUTPUT: Cycle 1(24): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:52 INFO - 2015-10-30 01:20:52,685 DEBUG : BROWSER_OUTPUT: RSS: Main: 268267520 01:20:52 INFO - 2015-10-30 01:20:52,685 DEBUG : BROWSER_OUTPUT: 01:20:53 INFO - 2015-10-30 01:20:53,409 DEBUG : BROWSER_OUTPUT: Cycle 1(25): loaded file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:53 INFO - 2015-10-30 01:20:53,667 DEBUG : BROWSER_OUTPUT: RSS: Main: 275505152 01:20:53 INFO - 2015-10-30 01:20:53,667 DEBUG : BROWSER_OUTPUT: 01:20:53 INFO - 2015-10-30 01:20:53,667 DEBUG : BROWSER_OUTPUT: __start_tp_report 01:20:53 INFO - 2015-10-30 01:20:53,667 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load 01:20:53 INFO - 2015-10-30 01:20:53,667 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load_details 01:20:53 INFO - 2015-10-30 01:20:53,667 DEBUG : BROWSER_OUTPUT: |i|pagename|runs| 01:20:53 INFO - 2015-10-30 01:20:53,667 DEBUG : BROWSER_OUTPUT: |0;dhtml.html;1044;1215;1217;1221;1205;1228;1223;1258;1235;1223;1110;1222;1254;1215;1138;1142;1110;1214;1211;1259;1217;1137;1213;1212;1224 01:20:53 INFO - 2015-10-30 01:20:53,668 DEBUG : BROWSER_OUTPUT: |1;tablemutation.html;272;274;268;273;262;266;261;264;261;264;262;263;264;264;261;268;260;263;260;261;271;257;262;262;261 01:20:53 INFO - 2015-10-30 01:20:53,668 DEBUG : BROWSER_OUTPUT: __end_tp_report 01:20:53 INFO - 2015-10-30 01:20:53,668 DEBUG : BROWSER_OUTPUT: __start_cc_report 01:20:53 INFO - 2015-10-30 01:20:53,668 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_cycle_collect,6211 01:20:53 INFO - 2015-10-30 01:20:53,668 DEBUG : BROWSER_OUTPUT: __end_cc_report 01:20:53 INFO - 2015-10-30 01:20:53,668 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193253660__endTimestamp 01:20:53 INFO - 2015-10-30 01:20:53,668 DEBUG : BROWSER_OUTPUT: 01:20:53 INFO - 2015-10-30 01:20:53,668 DEBUG : BROWSER_OUTPUT: ------- Summary: start ------- 01:20:53 INFO - 2015-10-30 01:20:53,669 DEBUG : BROWSER_OUTPUT: Number of tests: 2 01:20:53 INFO - 2015-10-30 01:20:53,669 DEBUG : BROWSER_OUTPUT: 01:20:53 INFO - 2015-10-30 01:20:53,669 DEBUG : BROWSER_OUTPUT: [#0] dhtml.html Cycles:25 Average:1197.88 Median:1215.00 stddev:53.08 (4.4%) stddev-sans-first:43.21 01:20:53 INFO - 2015-10-30 01:20:53,669 DEBUG : BROWSER_OUTPUT: Values: 1044.0 1215.0 1217.0 1221.0 1205.0 1228.0 1223.0 1258.0 1235.0 1223.0 1110.0 1222.0 1254.0 1215.0 1138.0 1142.0 1110.0 1214.0 1211.0 1259.0 1217.0 1137.0 1213.0 1212.0 1224.0 01:20:53 INFO - 2015-10-30 01:20:53,669 DEBUG : BROWSER_OUTPUT: 01:20:53 INFO - 2015-10-30 01:20:53,669 DEBUG : BROWSER_OUTPUT: [#1] tablemutation.html Cycles:25 Average:264.16 Median:263.00 stddev:4.44 (1.7%) stddev-sans-first:4.22 01:20:53 INFO - 2015-10-30 01:20:53,669 DEBUG : BROWSER_OUTPUT: Values: 272.0 274.0 268.0 273.0 262.0 266.0 261.0 264.0 261.0 264.0 262.0 263.0 264.0 264.0 261.0 268.0 260.0 263.0 260.0 261.0 271.0 257.0 262.0 262.0 261.0 01:20:53 INFO - 2015-10-30 01:20:53,670 DEBUG : BROWSER_OUTPUT: -------- Summary: end -------- 01:20:53 INFO - 2015-10-30 01:20:53,670 DEBUG : BROWSER_OUTPUT: 01:20:54 INFO - 2015-10-30 01:20:54,192 INFO : Browser exited with error code: 0 01:20:54 INFO - 2015-10-30 01:20:54,215 INFO : Completed test a11yr (00:01:38) 01:20:54 INFO - 2015-10-30 01:20:54,215 INFO : Starting test ts_paint 01:20:54 INFO - 2015-10-30 01:20:54,215 DEBUG : operating with platform_type : mac_ 01:20:54 INFO - 2015-10-30 01:20:54,215 INFO : Initialising browser for ts_paint test... 01:20:54 INFO - 2015-10-30 01:20:54,230 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/getInfo.html 01:20:56 INFO - 2015-10-30 01:20:56,532 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 01:20:56 INFO - 2015-10-30 01:20:56,533 DEBUG : BROWSER_OUTPUT: colorDepth:24 01:20:56 INFO - 2015-10-30 01:20:56,533 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/689 01:20:56 INFO - 2015-10-30 01:20:56,533 DEBUG : BROWSER_OUTPUT: __metrics 01:20:56 INFO - 2015-10-30 01:20:56,549 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 01:20:57 INFO - 2015-10-30 01:20:57,251 INFO : Browser initialized. 01:20:57 INFO - 2015-10-30 01:20:57,251 INFO : Running cycle 1/20 for ts_paint test... 01:20:57 INFO - 2015-10-30 01:20:57,251 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html 01:20:59 INFO - 2015-10-30 01:20:59,076 DEBUG : BROWSER_OUTPUT: __start_report1819__end_report 01:20:59 INFO - 2015-10-30 01:20:59,076 DEBUG : BROWSER_OUTPUT: 01:20:59 INFO - 2015-10-30 01:20:59,085 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193259084__endTimestamp 01:20:59 INFO - 2015-10-30 01:20:59,752 INFO : Browser exited with error code: 0 01:20:59 INFO - 2015-10-30 01:20:59,754 INFO : Running cycle 2/20 for ts_paint test... 01:20:59 INFO - 2015-10-30 01:20:59,754 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html 01:21:01 INFO - 2015-10-30 01:21:01,060 DEBUG : BROWSER_OUTPUT: __start_report1304__end_report 01:21:01 INFO - 2015-10-30 01:21:01,060 DEBUG : BROWSER_OUTPUT: 01:21:01 INFO - 2015-10-30 01:21:01,077 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193261070__endTimestamp 01:21:01 INFO - 2015-10-30 01:21:01,708 INFO : Browser exited with error code: 0 01:21:01 INFO - 2015-10-30 01:21:01,710 INFO : Running cycle 3/20 for ts_paint test... 01:21:01 INFO - 2015-10-30 01:21:01,710 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html 01:21:03 INFO - 2015-10-30 01:21:03,029 DEBUG : BROWSER_OUTPUT: __start_report1316__end_report 01:21:03 INFO - 2015-10-30 01:21:03,030 DEBUG : BROWSER_OUTPUT: 01:21:03 INFO - 2015-10-30 01:21:03,045 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193263039__endTimestamp 01:21:03 INFO - 2015-10-30 01:21:03,669 INFO : Browser exited with error code: 0 01:21:03 INFO - 2015-10-30 01:21:03,671 INFO : Running cycle 4/20 for ts_paint test... 01:21:03 INFO - 2015-10-30 01:21:03,671 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html 01:21:05 INFO - 2015-10-30 01:21:05,015 DEBUG : BROWSER_OUTPUT: __start_report1342__end_report 01:21:05 INFO - 2015-10-30 01:21:05,015 DEBUG : BROWSER_OUTPUT: 01:21:05 INFO - 2015-10-30 01:21:05,023 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193265022__endTimestamp 01:21:05 INFO - 2015-10-30 01:21:05,677 INFO : Browser exited with error code: 0 01:21:05 INFO - 2015-10-30 01:21:05,678 INFO : Running cycle 5/20 for ts_paint test... 01:21:05 INFO - 2015-10-30 01:21:05,678 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html 01:21:07 INFO - 2015-10-30 01:21:07,020 DEBUG : BROWSER_OUTPUT: __start_report1334__end_report 01:21:07 INFO - 2015-10-30 01:21:07,020 DEBUG : BROWSER_OUTPUT: 01:21:07 INFO - 2015-10-30 01:21:07,024 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193267022__endTimestamp 01:21:07 INFO - 2015-10-30 01:21:07,726 INFO : Browser exited with error code: 0 01:21:07 INFO - 2015-10-30 01:21:07,728 INFO : Running cycle 6/20 for ts_paint test... 01:21:07 INFO - 2015-10-30 01:21:07,728 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html 01:21:09 INFO - 2015-10-30 01:21:09,071 DEBUG : BROWSER_OUTPUT: __start_report1334__end_report 01:21:09 INFO - 2015-10-30 01:21:09,071 DEBUG : BROWSER_OUTPUT: 01:21:09 INFO - 2015-10-30 01:21:09,079 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193269076__endTimestamp 01:21:09 INFO - 2015-10-30 01:21:09,768 INFO : Browser exited with error code: 0 01:21:09 INFO - 2015-10-30 01:21:09,769 INFO : Running cycle 7/20 for ts_paint test... 01:21:09 INFO - 2015-10-30 01:21:09,769 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html 01:21:11 INFO - 2015-10-30 01:21:11,089 DEBUG : BROWSER_OUTPUT: __start_report1309__end_report 01:21:11 INFO - 2015-10-30 01:21:11,089 DEBUG : BROWSER_OUTPUT: 01:21:11 INFO - 2015-10-30 01:21:11,096 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193271096__endTimestamp 01:21:11 INFO - 2015-10-30 01:21:11,787 INFO : Browser exited with error code: 0 01:21:11 INFO - 2015-10-30 01:21:11,788 INFO : Running cycle 8/20 for ts_paint test... 01:21:11 INFO - 2015-10-30 01:21:11,789 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html 01:21:13 INFO - 2015-10-30 01:21:13,118 DEBUG : BROWSER_OUTPUT: __start_report1324__end_report 01:21:13 INFO - 2015-10-30 01:21:13,118 DEBUG : BROWSER_OUTPUT: 01:21:13 INFO - 2015-10-30 01:21:13,125 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193273122__endTimestamp 01:21:13 INFO - 2015-10-30 01:21:13,828 INFO : Browser exited with error code: 0 01:21:13 INFO - 2015-10-30 01:21:13,829 INFO : Running cycle 9/20 for ts_paint test... 01:21:13 INFO - 2015-10-30 01:21:13,829 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html 01:21:15 INFO - 2015-10-30 01:21:15,145 DEBUG : BROWSER_OUTPUT: __start_report1313__end_report 01:21:15 INFO - 2015-10-30 01:21:15,145 DEBUG : BROWSER_OUTPUT: 01:21:15 INFO - 2015-10-30 01:21:15,161 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193275155__endTimestamp 01:21:15 INFO - 2015-10-30 01:21:15,897 INFO : Browser exited with error code: 0 01:21:15 INFO - 2015-10-30 01:21:15,898 INFO : Running cycle 10/20 for ts_paint test... 01:21:15 INFO - 2015-10-30 01:21:15,898 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html 01:21:17 INFO - 2015-10-30 01:21:17,221 DEBUG : BROWSER_OUTPUT: __start_report1314__end_report 01:21:17 INFO - 2015-10-30 01:21:17,221 DEBUG : BROWSER_OUTPUT: 01:21:17 INFO - 2015-10-30 01:21:17,223 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193277222__endTimestamp 01:21:17 INFO - 2015-10-30 01:21:17,926 INFO : Browser exited with error code: 0 01:21:17 INFO - 2015-10-30 01:21:17,928 INFO : Running cycle 11/20 for ts_paint test... 01:21:17 INFO - 2015-10-30 01:21:17,928 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html 01:21:19 INFO - 2015-10-30 01:21:19,252 DEBUG : BROWSER_OUTPUT: __start_report1319__end_report 01:21:19 INFO - 2015-10-30 01:21:19,253 DEBUG : BROWSER_OUTPUT: 01:21:19 INFO - 2015-10-30 01:21:19,260 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193279258__endTimestamp 01:21:19 INFO - 2015-10-30 01:21:19,983 INFO : Browser exited with error code: 0 01:21:19 INFO - 2015-10-30 01:21:19,985 INFO : Running cycle 12/20 for ts_paint test... 01:21:19 INFO - 2015-10-30 01:21:19,985 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html 01:21:21 INFO - 2015-10-30 01:21:21,317 DEBUG : BROWSER_OUTPUT: __start_report1327__end_report 01:21:21 INFO - 2015-10-30 01:21:21,317 DEBUG : BROWSER_OUTPUT: 01:21:21 INFO - 2015-10-30 01:21:21,326 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193281323__endTimestamp 01:21:22 INFO - 2015-10-30 01:21:22,043 INFO : Browser exited with error code: 0 01:21:22 INFO - 2015-10-30 01:21:22,045 INFO : Running cycle 13/20 for ts_paint test... 01:21:22 INFO - 2015-10-30 01:21:22,045 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html 01:21:23 INFO - 2015-10-30 01:21:23,351 DEBUG : BROWSER_OUTPUT: __start_report1302__end_report 01:21:23 INFO - 2015-10-30 01:21:23,351 DEBUG : BROWSER_OUTPUT: 01:21:23 INFO - 2015-10-30 01:21:23,361 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193283356__endTimestamp 01:21:24 INFO - 2015-10-30 01:21:24,066 INFO : Browser exited with error code: 0 01:21:24 INFO - 2015-10-30 01:21:24,068 INFO : Running cycle 14/20 for ts_paint test... 01:21:24 INFO - 2015-10-30 01:21:24,068 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html 01:21:25 INFO - 2015-10-30 01:21:25,399 DEBUG : BROWSER_OUTPUT: __start_report1322__end_report 01:21:25 INFO - 2015-10-30 01:21:25,399 DEBUG : BROWSER_OUTPUT: 01:21:25 INFO - 2015-10-30 01:21:25,402 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193285402__endTimestamp 01:21:26 INFO - 2015-10-30 01:21:26,143 INFO : Browser exited with error code: 0 01:21:26 INFO - 2015-10-30 01:21:26,145 INFO : Running cycle 15/20 for ts_paint test... 01:21:26 INFO - 2015-10-30 01:21:26,145 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html 01:21:27 INFO - 2015-10-30 01:21:27,467 DEBUG : BROWSER_OUTPUT: __start_report1315__end_report 01:21:27 INFO - 2015-10-30 01:21:27,467 DEBUG : BROWSER_OUTPUT: 01:21:27 INFO - 2015-10-30 01:21:27,475 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193287472__endTimestamp 01:21:28 INFO - 2015-10-30 01:21:28,218 INFO : Browser exited with error code: 0 01:21:28 INFO - 2015-10-30 01:21:28,219 INFO : Running cycle 16/20 for ts_paint test... 01:21:28 INFO - 2015-10-30 01:21:28,219 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html 01:21:29 INFO - 2015-10-30 01:21:29,535 DEBUG : BROWSER_OUTPUT: __start_report1307__end_report 01:21:29 INFO - 2015-10-30 01:21:29,535 DEBUG : BROWSER_OUTPUT: 01:21:29 INFO - 2015-10-30 01:21:29,539 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193289538__endTimestamp 01:21:30 INFO - 2015-10-30 01:21:30,259 INFO : Browser exited with error code: 0 01:21:30 INFO - 2015-10-30 01:21:30,261 INFO : Running cycle 17/20 for ts_paint test... 01:21:30 INFO - 2015-10-30 01:21:30,261 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html 01:21:31 INFO - 2015-10-30 01:21:31,583 DEBUG : BROWSER_OUTPUT: __start_report1317__end_report 01:21:31 INFO - 2015-10-30 01:21:31,583 DEBUG : BROWSER_OUTPUT: 01:21:31 INFO - 2015-10-30 01:21:31,601 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193291590__endTimestamp 01:21:32 INFO - 2015-10-30 01:21:32,363 INFO : Browser exited with error code: 0 01:21:32 INFO - 2015-10-30 01:21:32,364 INFO : Running cycle 18/20 for ts_paint test... 01:21:32 INFO - 2015-10-30 01:21:32,364 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html 01:21:33 INFO - 2015-10-30 01:21:33,680 DEBUG : BROWSER_OUTPUT: __start_report1312__end_report 01:21:33 INFO - 2015-10-30 01:21:33,680 DEBUG : BROWSER_OUTPUT: 01:21:33 INFO - 2015-10-30 01:21:33,699 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193293688__endTimestamp 01:21:34 INFO - 2015-10-30 01:21:34,519 INFO : Browser exited with error code: 0 01:21:34 INFO - 2015-10-30 01:21:34,520 INFO : Running cycle 19/20 for ts_paint test... 01:21:34 INFO - 2015-10-30 01:21:34,521 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html 01:21:35 INFO - 2015-10-30 01:21:35,850 DEBUG : BROWSER_OUTPUT: __start_report1327__end_report 01:21:35 INFO - 2015-10-30 01:21:35,850 DEBUG : BROWSER_OUTPUT: 01:21:35 INFO - 2015-10-30 01:21:35,858 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193295857__endTimestamp 01:21:36 INFO - 2015-10-30 01:21:36,572 INFO : Browser exited with error code: 0 01:21:36 INFO - 2015-10-30 01:21:36,573 INFO : Running cycle 20/20 for ts_paint test... 01:21:36 INFO - 2015-10-30 01:21:36,573 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpwaYNNS/profile http://localhost/startup_test/tspaint_test.html 01:21:37 INFO - 2015-10-30 01:21:37,876 DEBUG : BROWSER_OUTPUT: __start_report1299__end_report 01:21:37 INFO - 2015-10-30 01:21:37,876 DEBUG : BROWSER_OUTPUT: 01:21:37 INFO - 2015-10-30 01:21:37,894 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193297887__endTimestamp 01:21:38 INFO - 2015-10-30 01:21:38,602 INFO : Browser exited with error code: 0 01:21:38 INFO - 2015-10-30 01:21:38,629 INFO : Completed test ts_paint (00:00:44) 01:21:38 INFO - 2015-10-30 01:21:38,629 INFO : Starting test tpaint 01:21:38 INFO - 2015-10-30 01:21:38,630 DEBUG : operating with platform_type : mac_ 01:21:38 INFO - 2015-10-30 01:21:38,630 INFO : Initialising browser for tpaint test... 01:21:38 INFO - 2015-10-30 01:21:38,643 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpKkln0C/profile http://localhost/getInfo.html 01:21:41 INFO - 2015-10-30 01:21:41,236 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 01:21:41 INFO - 2015-10-30 01:21:41,236 DEBUG : BROWSER_OUTPUT: colorDepth:24 01:21:41 INFO - 2015-10-30 01:21:41,236 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/689 01:21:41 INFO - 2015-10-30 01:21:41,236 DEBUG : BROWSER_OUTPUT: __metrics 01:21:41 INFO - 2015-10-30 01:21:41,252 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 01:21:41 INFO - 2015-10-30 01:21:41,937 INFO : Browser initialized. 01:21:41 INFO - 2015-10-30 01:21:41,938 INFO : Running cycle 1/1 for tpaint test... 01:21:41 INFO - 2015-10-30 01:21:41,938 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpKkln0C/profile file:///builds/slave/test/build/tests/talos/talos/startup_test/tpaint.html?auto=1 01:22:10 INFO - 2015-10-30 01:22:10,353 DEBUG : BROWSER_OUTPUT: __start_report291.4549999999999|298.97500000000036|300.6700000000001|304.2699999999995|307.1900000000005|307.90999999999985|308.10499999999956|309.0750000000007|310.4949999999999|312.15999999999985|313.3250000000007|314.4549999999999|314.96500000000015|316.1750000000029|318.28499999999985|333.8199999999997|336.7400000000016|385.89500000000044|396.2999999999993|482.619999999999__end_report__startTimestamp1446193330350__endTimestamp 01:22:10 INFO - 2015-10-30 01:22:10,354 DEBUG : BROWSER_OUTPUT: openingTimes=298.97500000000036,300.6700000000001,304.2699999999995,307.1900000000005,307.90999999999985,308.10499999999956,309.0750000000007,310.4949999999999,312.15999999999985,313.3250000000007,314.4549999999999,314.96500000000015,316.1750000000029,318.28499999999985,333.8199999999997,336.7400000000016,385.89500000000044,396.2999999999993,482.619999999999 01:22:10 INFO - 2015-10-30 01:22:10,354 DEBUG : BROWSER_OUTPUT: avgOpenTime:328.14 01:22:10 INFO - 2015-10-30 01:22:10,354 DEBUG : BROWSER_OUTPUT: minOpenTime:291.45 01:22:10 INFO - 2015-10-30 01:22:10,354 DEBUG : BROWSER_OUTPUT: maxOpenTime:482.62 01:22:10 INFO - 2015-10-30 01:22:10,354 DEBUG : BROWSER_OUTPUT: medOpenTime:312.7425000000003 01:22:10 INFO - 2015-10-30 01:22:10,354 DEBUG : BROWSER_OUTPUT: __xulWinOpenTime:312.7425000000003 01:22:11 INFO - 2015-10-30 01:22:11,110 INFO : Browser exited with error code: 0 01:22:11 INFO - 2015-10-30 01:22:11,130 INFO : Completed test tpaint (00:00:32) 01:22:11 INFO - 2015-10-30 01:22:11,131 INFO : Starting test sessionrestore 01:22:11 INFO - 2015-10-30 01:22:11,131 DEBUG : operating with platform_type : mac_ 01:22:11 INFO - 2015-10-30 01:22:11,131 INFO : Initialising browser for sessionrestore test... 01:22:11 INFO - 2015-10-30 01:22:11,149 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile http://localhost/getInfo.html 01:22:13 INFO - 2015-10-30 01:22:13,558 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 01:22:13 INFO - 2015-10-30 01:22:13,558 DEBUG : BROWSER_OUTPUT: colorDepth:24 01:22:13 INFO - 2015-10-30 01:22:13,559 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1200/743 01:22:13 INFO - 2015-10-30 01:22:13,559 DEBUG : BROWSER_OUTPUT: __metrics 01:22:13 INFO - 2015-10-30 01:22:13,575 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 01:22:14 INFO - 2015-10-30 01:22:14,346 INFO : Browser initialized. 01:22:14 INFO - 2015-10-30 01:22:14,347 INFO : Running cycle 1/10 for sessionrestore test... 01:22:14 INFO - 2015-10-30 01:22:14,347 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile/sessionstore.js 01:22:14 INFO - 2015-10-30 01:22:14,352 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile http://localhost/startup_test/sessionrestore/index.html 01:22:19 INFO - 2015-10-30 01:22:19,373 DEBUG : BROWSER_OUTPUT: __start_report2641__end_report 01:22:19 INFO - 2015-10-30 01:22:19,373 DEBUG : BROWSER_OUTPUT: 01:22:19 INFO - 2015-10-30 01:22:19,373 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193339369__endTimestamp 01:22:19 INFO - 2015-10-30 01:22:19,373 DEBUG : BROWSER_OUTPUT: 01:22:20 INFO - 2015-10-30 01:22:20,656 INFO : Browser exited with error code: 0 01:22:20 INFO - 2015-10-30 01:22:20,658 INFO : Running cycle 2/10 for sessionrestore test... 01:22:20 INFO - 2015-10-30 01:22:20,658 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile/sessionstore.js 01:22:20 INFO - 2015-10-30 01:22:20,664 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile http://localhost/startup_test/sessionrestore/index.html 01:22:24 INFO - 2015-10-30 01:22:24,509 DEBUG : BROWSER_OUTPUT: __start_report2309__end_report 01:22:24 INFO - 2015-10-30 01:22:24,509 DEBUG : BROWSER_OUTPUT: 01:22:24 INFO - 2015-10-30 01:22:24,509 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193344508__endTimestamp 01:22:24 INFO - 2015-10-30 01:22:24,509 DEBUG : BROWSER_OUTPUT: 01:22:26 INFO - 2015-10-30 01:22:26,053 INFO : Browser exited with error code: 0 01:22:26 INFO - 2015-10-30 01:22:26,055 INFO : Running cycle 3/10 for sessionrestore test... 01:22:26 INFO - 2015-10-30 01:22:26,055 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile/sessionstore.js 01:22:26 INFO - 2015-10-30 01:22:26,060 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile http://localhost/startup_test/sessionrestore/index.html 01:22:29 INFO - 2015-10-30 01:22:29,906 DEBUG : BROWSER_OUTPUT: __start_report2317__end_report 01:22:29 INFO - 2015-10-30 01:22:29,906 DEBUG : BROWSER_OUTPUT: 01:22:29 INFO - 2015-10-30 01:22:29,906 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193349905__endTimestamp 01:22:29 INFO - 2015-10-30 01:22:29,906 DEBUG : BROWSER_OUTPUT: 01:22:31 INFO - 2015-10-30 01:22:31,464 INFO : Browser exited with error code: 0 01:22:31 INFO - 2015-10-30 01:22:31,465 INFO : Running cycle 4/10 for sessionrestore test... 01:22:31 INFO - 2015-10-30 01:22:31,465 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile/sessionstore.js 01:22:31 INFO - 2015-10-30 01:22:31,471 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile http://localhost/startup_test/sessionrestore/index.html 01:22:35 INFO - 2015-10-30 01:22:35,327 DEBUG : BROWSER_OUTPUT: __start_report2307__end_report 01:22:35 INFO - 2015-10-30 01:22:35,328 DEBUG : BROWSER_OUTPUT: 01:22:35 INFO - 2015-10-30 01:22:35,328 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193355326__endTimestamp 01:22:35 INFO - 2015-10-30 01:22:35,328 DEBUG : BROWSER_OUTPUT: 01:22:36 INFO - 2015-10-30 01:22:36,945 INFO : Browser exited with error code: 0 01:22:36 INFO - 2015-10-30 01:22:36,947 INFO : Running cycle 5/10 for sessionrestore test... 01:22:36 INFO - 2015-10-30 01:22:36,947 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile/sessionstore.js 01:22:36 INFO - 2015-10-30 01:22:36,952 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile http://localhost/startup_test/sessionrestore/index.html 01:22:40 INFO - 2015-10-30 01:22:40,811 DEBUG : BROWSER_OUTPUT: __start_report2317__end_report 01:22:40 INFO - 2015-10-30 01:22:40,811 DEBUG : BROWSER_OUTPUT: 01:22:40 INFO - 2015-10-30 01:22:40,811 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193360809__endTimestamp 01:22:40 INFO - 2015-10-30 01:22:40,812 DEBUG : BROWSER_OUTPUT: 01:22:42 INFO - 2015-10-30 01:22:42,465 INFO : Browser exited with error code: 0 01:22:42 INFO - 2015-10-30 01:22:42,467 INFO : Running cycle 6/10 for sessionrestore test... 01:22:42 INFO - 2015-10-30 01:22:42,467 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile/sessionstore.js 01:22:42 INFO - 2015-10-30 01:22:42,472 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile http://localhost/startup_test/sessionrestore/index.html 01:22:46 INFO - 2015-10-30 01:22:46,318 DEBUG : BROWSER_OUTPUT: __start_report2318__end_report 01:22:46 INFO - 2015-10-30 01:22:46,319 DEBUG : BROWSER_OUTPUT: 01:22:46 INFO - 2015-10-30 01:22:46,319 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193366316__endTimestamp 01:22:46 INFO - 2015-10-30 01:22:46,319 DEBUG : BROWSER_OUTPUT: 01:22:47 INFO - 2015-10-30 01:22:47,965 INFO : Browser exited with error code: 0 01:22:47 INFO - 2015-10-30 01:22:47,966 INFO : Running cycle 7/10 for sessionrestore test... 01:22:47 INFO - 2015-10-30 01:22:47,966 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile/sessionstore.js 01:22:47 INFO - 2015-10-30 01:22:47,972 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile http://localhost/startup_test/sessionrestore/index.html 01:22:51 INFO - 2015-10-30 01:22:51,819 DEBUG : BROWSER_OUTPUT: __start_report2308__end_report 01:22:51 INFO - 2015-10-30 01:22:51,819 DEBUG : BROWSER_OUTPUT: 01:22:51 INFO - 2015-10-30 01:22:51,819 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193371817__endTimestamp 01:22:51 INFO - 2015-10-30 01:22:51,819 DEBUG : BROWSER_OUTPUT: 01:22:53 INFO - 2015-10-30 01:22:53,464 INFO : Browser exited with error code: 0 01:22:53 INFO - 2015-10-30 01:22:53,465 INFO : Running cycle 8/10 for sessionrestore test... 01:22:53 INFO - 2015-10-30 01:22:53,465 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile/sessionstore.js 01:22:53 INFO - 2015-10-30 01:22:53,471 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile http://localhost/startup_test/sessionrestore/index.html 01:22:57 INFO - 2015-10-30 01:22:57,314 DEBUG : BROWSER_OUTPUT: __start_report2319__end_report 01:22:57 INFO - 2015-10-30 01:22:57,315 DEBUG : BROWSER_OUTPUT: 01:22:57 INFO - 2015-10-30 01:22:57,315 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193377311__endTimestamp 01:22:57 INFO - 2015-10-30 01:22:57,315 DEBUG : BROWSER_OUTPUT: 01:22:58 INFO - 2015-10-30 01:22:58,947 INFO : Browser exited with error code: 0 01:22:58 INFO - 2015-10-30 01:22:58,948 INFO : Running cycle 9/10 for sessionrestore test... 01:22:58 INFO - 2015-10-30 01:22:58,949 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile/sessionstore.js 01:22:58 INFO - 2015-10-30 01:22:58,954 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile http://localhost/startup_test/sessionrestore/index.html 01:23:02 INFO - 2015-10-30 01:23:02,803 DEBUG : BROWSER_OUTPUT: __start_report2310__end_report 01:23:02 INFO - 2015-10-30 01:23:02,803 DEBUG : BROWSER_OUTPUT: 01:23:02 INFO - 2015-10-30 01:23:02,803 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193382802__endTimestamp 01:23:02 INFO - 2015-10-30 01:23:02,803 DEBUG : BROWSER_OUTPUT: 01:23:04 INFO - 2015-10-30 01:23:04,558 INFO : Browser exited with error code: 0 01:23:04 INFO - 2015-10-30 01:23:04,560 INFO : Running cycle 10/10 for sessionrestore test... 01:23:04 INFO - 2015-10-30 01:23:04,560 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile/sessionstore.js 01:23:04 INFO - 2015-10-30 01:23:04,565 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmph2buWs/profile http://localhost/startup_test/sessionrestore/index.html 01:23:08 INFO - 2015-10-30 01:23:08,389 DEBUG : BROWSER_OUTPUT: __start_report2303__end_report 01:23:08 INFO - 2015-10-30 01:23:08,389 DEBUG : BROWSER_OUTPUT: 01:23:08 INFO - 2015-10-30 01:23:08,390 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193388388__endTimestamp 01:23:08 INFO - 2015-10-30 01:23:08,390 DEBUG : BROWSER_OUTPUT: 01:23:10 INFO - 2015-10-30 01:23:10,056 INFO : Browser exited with error code: 0 01:23:10 INFO - 2015-10-30 01:23:10,079 INFO : Completed test sessionrestore (00:00:58) 01:23:10 INFO - 2015-10-30 01:23:10,079 INFO : Starting test sessionrestore_no_auto_restore 01:23:10 INFO - 2015-10-30 01:23:10,079 DEBUG : operating with platform_type : mac_ 01:23:10 INFO - 2015-10-30 01:23:10,080 INFO : Initialising browser for sessionrestore_no_auto_restore test... 01:23:10 INFO - 2015-10-30 01:23:10,100 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile http://localhost/getInfo.html 01:23:12 INFO - 2015-10-30 01:23:12,697 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 01:23:12 INFO - 2015-10-30 01:23:12,698 DEBUG : BROWSER_OUTPUT: colorDepth:24 01:23:12 INFO - 2015-10-30 01:23:12,698 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1200/743 01:23:12 INFO - 2015-10-30 01:23:12,698 DEBUG : BROWSER_OUTPUT: __metrics 01:23:12 INFO - 2015-10-30 01:23:12,714 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 01:23:13 INFO - 2015-10-30 01:23:13,498 INFO : Browser initialized. 01:23:13 INFO - 2015-10-30 01:23:13,499 INFO : Running cycle 1/10 for sessionrestore_no_auto_restore test... 01:23:13 INFO - 2015-10-30 01:23:13,499 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile/sessionstore.js 01:23:13 INFO - 2015-10-30 01:23:13,505 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile http://localhost/startup_test/sessionrestore/index.html 01:23:15 INFO - 2015-10-30 01:23:15,358 DEBUG : BROWSER_OUTPUT: __start_report1313__end_report 01:23:15 INFO - 2015-10-30 01:23:15,358 DEBUG : BROWSER_OUTPUT: 01:23:15 INFO - 2015-10-30 01:23:15,358 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193395355__endTimestamp 01:23:15 INFO - 2015-10-30 01:23:15,358 DEBUG : BROWSER_OUTPUT: 01:23:16 INFO - 2015-10-30 01:23:16,004 INFO : Browser exited with error code: 0 01:23:16 INFO - 2015-10-30 01:23:16,006 INFO : Running cycle 2/10 for sessionrestore_no_auto_restore test... 01:23:16 INFO - 2015-10-30 01:23:16,006 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile/sessionstore.js 01:23:16 INFO - 2015-10-30 01:23:16,029 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile http://localhost/startup_test/sessionrestore/index.html 01:23:17 INFO - 2015-10-30 01:23:17,476 DEBUG : BROWSER_OUTPUT: __start_report1014__end_report 01:23:17 INFO - 2015-10-30 01:23:17,476 DEBUG : BROWSER_OUTPUT: 01:23:17 INFO - 2015-10-30 01:23:17,476 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193397473__endTimestamp 01:23:17 INFO - 2015-10-30 01:23:17,476 DEBUG : BROWSER_OUTPUT: 01:23:18 INFO - 2015-10-30 01:23:18,114 INFO : Browser exited with error code: 0 01:23:18 INFO - 2015-10-30 01:23:18,116 INFO : Running cycle 3/10 for sessionrestore_no_auto_restore test... 01:23:18 INFO - 2015-10-30 01:23:18,116 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile/sessionstore.js 01:23:18 INFO - 2015-10-30 01:23:18,122 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile http://localhost/startup_test/sessionrestore/index.html 01:23:19 INFO - 2015-10-30 01:23:19,571 DEBUG : BROWSER_OUTPUT: __start_report1016__end_report 01:23:19 INFO - 2015-10-30 01:23:19,571 DEBUG : BROWSER_OUTPUT: 01:23:19 INFO - 2015-10-30 01:23:19,572 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193399571__endTimestamp 01:23:19 INFO - 2015-10-30 01:23:19,572 DEBUG : BROWSER_OUTPUT: 01:23:20 INFO - 2015-10-30 01:23:20,227 INFO : Browser exited with error code: 0 01:23:20 INFO - 2015-10-30 01:23:20,229 INFO : Running cycle 4/10 for sessionrestore_no_auto_restore test... 01:23:20 INFO - 2015-10-30 01:23:20,229 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile/sessionstore.js 01:23:20 INFO - 2015-10-30 01:23:20,235 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile http://localhost/startup_test/sessionrestore/index.html 01:23:21 INFO - 2015-10-30 01:23:21,681 DEBUG : BROWSER_OUTPUT: __start_report1001__end_report 01:23:21 INFO - 2015-10-30 01:23:21,681 DEBUG : BROWSER_OUTPUT: 01:23:21 INFO - 2015-10-30 01:23:21,682 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193401680__endTimestamp 01:23:21 INFO - 2015-10-30 01:23:21,682 DEBUG : BROWSER_OUTPUT: 01:23:22 INFO - 2015-10-30 01:23:22,401 INFO : Browser exited with error code: 0 01:23:22 INFO - 2015-10-30 01:23:22,402 INFO : Running cycle 5/10 for sessionrestore_no_auto_restore test... 01:23:22 INFO - 2015-10-30 01:23:22,402 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile/sessionstore.js 01:23:22 INFO - 2015-10-30 01:23:22,407 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile http://localhost/startup_test/sessionrestore/index.html 01:23:23 INFO - 2015-10-30 01:23:23,860 DEBUG : BROWSER_OUTPUT: __start_report1007__end_report 01:23:23 INFO - 2015-10-30 01:23:23,860 DEBUG : BROWSER_OUTPUT: 01:23:23 INFO - 2015-10-30 01:23:23,860 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193403857__endTimestamp 01:23:23 INFO - 2015-10-30 01:23:23,860 DEBUG : BROWSER_OUTPUT: 01:23:24 INFO - 2015-10-30 01:23:24,598 INFO : Browser exited with error code: 0 01:23:24 INFO - 2015-10-30 01:23:24,599 INFO : Running cycle 6/10 for sessionrestore_no_auto_restore test... 01:23:24 INFO - 2015-10-30 01:23:24,600 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile/sessionstore.js 01:23:24 INFO - 2015-10-30 01:23:24,605 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile http://localhost/startup_test/sessionrestore/index.html 01:23:26 INFO - 2015-10-30 01:23:26,060 DEBUG : BROWSER_OUTPUT: __start_report1010__end_report 01:23:26 INFO - 2015-10-30 01:23:26,060 DEBUG : BROWSER_OUTPUT: 01:23:26 INFO - 2015-10-30 01:23:26,060 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193406059__endTimestamp 01:23:26 INFO - 2015-10-30 01:23:26,060 DEBUG : BROWSER_OUTPUT: 01:23:26 INFO - 2015-10-30 01:23:26,815 INFO : Browser exited with error code: 0 01:23:26 INFO - 2015-10-30 01:23:26,817 INFO : Running cycle 7/10 for sessionrestore_no_auto_restore test... 01:23:26 INFO - 2015-10-30 01:23:26,817 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile/sessionstore.js 01:23:26 INFO - 2015-10-30 01:23:26,823 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile http://localhost/startup_test/sessionrestore/index.html 01:23:28 INFO - 2015-10-30 01:23:28,253 DEBUG : BROWSER_OUTPUT: __start_report997__end_report 01:23:28 INFO - 2015-10-30 01:23:28,253 DEBUG : BROWSER_OUTPUT: 01:23:28 INFO - 2015-10-30 01:23:28,253 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193408252__endTimestamp 01:23:28 INFO - 2015-10-30 01:23:28,253 DEBUG : BROWSER_OUTPUT: 01:23:29 INFO - 2015-10-30 01:23:29,015 INFO : Browser exited with error code: 0 01:23:29 INFO - 2015-10-30 01:23:29,018 INFO : Running cycle 8/10 for sessionrestore_no_auto_restore test... 01:23:29 INFO - 2015-10-30 01:23:29,018 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile/sessionstore.js 01:23:29 INFO - 2015-10-30 01:23:29,023 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile http://localhost/startup_test/sessionrestore/index.html 01:23:30 INFO - 2015-10-30 01:23:30,470 DEBUG : BROWSER_OUTPUT: __start_report1013__end_report 01:23:30 INFO - 2015-10-30 01:23:30,470 DEBUG : BROWSER_OUTPUT: 01:23:30 INFO - 2015-10-30 01:23:30,470 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193410468__endTimestamp 01:23:30 INFO - 2015-10-30 01:23:30,470 DEBUG : BROWSER_OUTPUT: 01:23:31 INFO - 2015-10-30 01:23:31,226 INFO : Browser exited with error code: 0 01:23:31 INFO - 2015-10-30 01:23:31,227 INFO : Running cycle 9/10 for sessionrestore_no_auto_restore test... 01:23:31 INFO - 2015-10-30 01:23:31,228 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile/sessionstore.js 01:23:31 INFO - 2015-10-30 01:23:31,234 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile http://localhost/startup_test/sessionrestore/index.html 01:23:32 INFO - 2015-10-30 01:23:32,675 DEBUG : BROWSER_OUTPUT: __start_report1007__end_report 01:23:32 INFO - 2015-10-30 01:23:32,675 DEBUG : BROWSER_OUTPUT: 01:23:32 INFO - 2015-10-30 01:23:32,675 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193412671__endTimestamp 01:23:32 INFO - 2015-10-30 01:23:32,676 DEBUG : BROWSER_OUTPUT: 01:23:33 INFO - 2015-10-30 01:23:33,455 INFO : Browser exited with error code: 0 01:23:33 INFO - 2015-10-30 01:23:33,457 INFO : Running cycle 10/10 for sessionrestore_no_auto_restore test... 01:23:33 INFO - 2015-10-30 01:23:33,457 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile/sessionstore.js 01:23:33 INFO - 2015-10-30 01:23:33,463 DEBUG : command line: /builds/slave/test/build/application/FirefoxDeveloperEdition.app/Contents/MacOS/firefox -foreground -profile /var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/T/tmpBUlhin/profile http://localhost/startup_test/sessionrestore/index.html 01:23:34 INFO - 2015-10-30 01:23:34,905 DEBUG : BROWSER_OUTPUT: __start_report1007__end_report 01:23:34 INFO - 2015-10-30 01:23:34,906 DEBUG : BROWSER_OUTPUT: 01:23:34 INFO - 2015-10-30 01:23:34,906 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193414897__endTimestamp 01:23:34 INFO - 2015-10-30 01:23:34,906 DEBUG : BROWSER_OUTPUT: 01:23:35 INFO - 2015-10-30 01:23:35,664 INFO : Browser exited with error code: 0 01:23:35 INFO - 2015-10-30 01:23:35,687 INFO : Completed test sessionrestore_no_auto_restore (00:00:25) 01:23:35 INFO - 2015-10-30 01:23:35,687 INFO : Completed test suite (00:04:19) 01:23:35 INFO - 2015-10-30 01:23:35,687 DEBUG : Working with test: a11yr 01:23:35 INFO - 2015-10-30 01:23:35,687 DEBUG : Generating results file: a11yr 01:23:35 INFO - 2015-10-30 01:23:35,687 DEBUG : Working with test: ts_paint 01:23:35 INFO - 2015-10-30 01:23:35,688 DEBUG : Generating results file: ts_paint 01:23:35 INFO - 2015-10-30 01:23:35,688 DEBUG : Working with test: tpaint 01:23:35 INFO - 2015-10-30 01:23:35,689 DEBUG : Generating results file: tpaint 01:23:35 INFO - 2015-10-30 01:23:35,689 DEBUG : Working with test: sessionrestore 01:23:35 INFO - 2015-10-30 01:23:35,689 DEBUG : Generating results file: sessionrestore 01:23:35 INFO - 2015-10-30 01:23:35,689 DEBUG : Working with test: sessionrestore_no_auto_restore 01:23:35 INFO - 2015-10-30 01:23:35,689 DEBUG : Generating results file: sessionrestore_no_auto_restore 01:23:35 INFO - 2015-10-30 01:23:35,690 INFO : Posting result 0 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 01:23:35 INFO - 2015-10-30 01:23:35,741 DEBUG : process_Request line: a11yr_paint graph.html#tests=[[223,52,55]] 01:23:35 INFO - 2015-10-30 01:23:35,741 DEBUG : process_Request line: a11yr_paint 565.29 graph.html#tests=[[223,52,55]] 01:23:35 INFO - 2015-10-30 01:23:35,741 INFO : Posting result 1 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 01:23:35 INFO - 2015-10-30 01:23:35,803 DEBUG : process_Request line: ts_paint graph.html#tests=[[83,52,55]] 01:23:35 INFO - 2015-10-30 01:23:35,803 DEBUG : process_Request line: ts_paint 1339.10 graph.html#tests=[[83,52,55]] 01:23:35 INFO - 2015-10-30 01:23:35,803 INFO : Posting result 2 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 01:23:35 INFO - 2015-10-30 01:23:35,837 DEBUG : process_Request line: tpaint graph.html#tests=[[82,52,55]] 01:23:35 INFO - 2015-10-30 01:23:35,837 DEBUG : process_Request line: tpaint 314.97 graph.html#tests=[[82,52,55]] 01:23:35 INFO - 2015-10-30 01:23:35,837 INFO : Posting result 3 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 01:23:35 INFO - 2015-10-30 01:23:35,891 DEBUG : process_Request line: sessionrestore graph.html#tests=[[313,52,55]] 01:23:35 INFO - 2015-10-30 01:23:35,891 DEBUG : process_Request line: sessionrestore 2342.96 graph.html#tests=[[313,52,55]] 01:23:35 INFO - 2015-10-30 01:23:35,892 INFO : Posting result 4 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 01:23:35 INFO - 2015-10-30 01:23:35,943 DEBUG : process_Request line: sessionrestore_no_auto_restore graph.html#tests=[[315,52,55]] 01:23:35 INFO - 2015-10-30 01:23:35,943 DEBUG : process_Request line: sessionrestore_no_auto_restore 1034.99 graph.html#tests=[[315,52,55]] 01:23:35 INFO - 2015-10-30 01:23:35,944 INFO : TALOSDATA: [{"talos_counters": {}, "results": {"dhtml.html": [1044.0, 1215.0, 1217.0, 1221.0, 1205.0, 1228.0, 1223.0, 1258.0, 1235.0, 1223.0, 1110.0, 1222.0, 1254.0, 1215.0, 1138.0, 1142.0, 1110.0, 1214.0, 1211.0, 1259.0, 1217.0, 1137.0, 1213.0, 1212.0, 1224.0], "tablemutation.html": [272.0, 274.0, 268.0, 273.0, 262.0, 266.0, 261.0, 264.0, 261.0, 264.0, 262.0, 263.0, 264.0, 264.0, 261.0, 268.0, 260.0, 263.0, 260.0, 261.0, 271.0, 257.0, 262.0, 262.0, 261.0]}, "summary": {"suite": 565.2857052760558, "subtests": {"dhtml.html": {"std": 42.30196918846949, "min": 1110.0, "max": 1259.0, "median": 1216.0, "filtered": 1216.0, "mean": 1204.2916666666667}, "tablemutation.html": {"std": 4.129837231121288, "min": 257.0, "max": 274.0, "median": 262.5, "filtered": 262.5, "mean": 263.8333333333333}}}, "test_machine": {"platform": "x86_64", "osversion": "OS X 10.10.2", "os": "mac", "name": "t-yosemite-r5-0025"}, "testrun": {"date": 1446193156, "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": "43.0a2", "id": "20151029014646", "branch": "Mozilla-Aurora", "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797"}}, {"talos_counters": {}, "results": {"ts_paint": [1819.0, 1304.0, 1316.0, 1342.0, 1334.0, 1334.0, 1309.0, 1324.0, 1313.0, 1314.0, 1319.0, 1327.0, 1302.0, 1322.0, 1315.0, 1307.0, 1317.0, 1312.0, 1327.0, 1299.0]}, "summary": {"suite": 1316.0, "subtests": {"ts_paint": {"std": 11.257007666633626, "min": 1299.0, "max": 1342.0, "median": 1316.0, "filtered": 1316.0, "mean": 1317.7368421052631}}}, "test_machine": {"platform": "x86_64", "osversion": "OS X 10.10.2", "os": "mac", "name": "t-yosemite-r5-0025"}, "testrun": {"date": 1446193156, "suite": "ts_paint", "options": {"responsiveness": false, "cycles": 20, "tpmozafterpaint": true, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "43.0a2", "id": "20151029014646", "branch": "Mozilla-Aurora", "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797"}}, {"talos_counters": {}, "results": {"tpaint": [291.4549999999999, 298.97500000000036, 300.6700000000001, 304.2699999999995, 307.1900000000005, 307.90999999999985, 308.10499999999956, 309.0750000000007, 310.4949999999999, 312.15999999999985, 313.3250000000007, 314.4549999999999, 314.96500000000015, 316.1750000000029, 318.28499999999985, 333.8199999999997, 336.7400000000016, 385.89500000000044, 396.2999999999993, 482.619999999999]}, "summary": {"suite": 314.96500000000015, "subtests": {"tpaint": {"std": 47.07400992054924, "min": 307.90999999999985, "max": 482.619999999999, "median": 314.96500000000015, "filtered": 314.96500000000015, "mean": 337.35500000000025}}}, "test_machine": {"platform": "x86_64", "osversion": "OS X 10.10.2", "os": "mac", "name": "t-yosemite-r5-0025"}, "testrun": {"date": 1446193156, "suite": "tpaint", "options": {"responsiveness": false, "cycles": 1, "tpmozafterpaint": true, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "43.0a2", "id": "20151029014646", "branch": "Mozilla-Aurora", "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797"}}, {"talos_counters": {}, "results": {"sessionrestore": [2641.0, 2309.0, 2317.0, 2307.0, 2317.0, 2318.0, 2308.0, 2319.0, 2310.0, 2303.0]}, "summary": {"suite": 2310.0, "subtests": {"sessionrestore": {"std": 5.477225575051661, "min": 2303.0, "max": 2319.0, "median": 2310.0, "filtered": 2310.0, "mean": 2312.0}}}, "test_machine": {"platform": "x86_64", "osversion": "OS X 10.10.2", "os": "mac", "name": "t-yosemite-r5-0025"}, "testrun": {"date": 1446193156, "suite": "sessionrestore", "options": {"responsiveness": false, "cycles": 10, "tpmozafterpaint": false, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "43.0a2", "id": "20151029014646", "branch": "Mozilla-Aurora", "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797"}}, {"talos_counters": {}, "results": {"sessionrestore_no_auto_restore": [1313.0, 1014.0, 1016.0, 1001.0, 1007.0, 1010.0, 997.0, 1013.0, 1007.0, 1007.0]}, "summary": {"suite": 1007.0, "subtests": {"sessionrestore_no_auto_restore": {"std": 5.792715732327589, "min": 997.0, "max": 1016.0, "median": 1007.0, "filtered": 1007.0, "mean": 1008.0}}}, "test_machine": {"platform": "x86_64", "osversion": "OS X 10.10.2", "os": "mac", "name": "t-yosemite-r5-0025"}, "testrun": {"date": 1446193156, "suite": "sessionrestore_no_auto_restore", "options": {"responsiveness": false, "cycles": 10, "tpmozafterpaint": false, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "43.0a2", "id": "20151029014646", "branch": "Mozilla-Aurora", "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797"}}] 01:23:35 INFO - RETURN: a11yr_paint: 565.29 01:23:35 INFO - RETURN: ts_paint: 1339.10 01:23:35 INFO - RETURN: tpaint: 314.97 01:23:35 INFO - RETURN: sessionrestore: 2342.96 01:23:35 INFO - RETURN: sessionrestore_no_auto_restore: 1034.99 01:23:35 INFO - TinderboxPrint: TalosResult: {"graphserver": {"sessionrestore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[313,52,55]]", "result": "2342.96"}, "a11yr_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[223,52,55]]", "result": "565.29"}, "tpaint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[82,52,55]]", "result": "314.97"}, "ts_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[83,52,55]]", "result": "1339.10"}, "sessionrestore_no_auto_restore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[315,52,55]]", "result": "1034.99"}}} 01:23:35 INFO - Return code: 0 01:23:35 INFO - # TBPL SUCCESS # 01:23:35 INFO - Running pre test command check_screen_resolution with 'bash -c screenresolution get && screenresolution list && system_profiler SPDisplaysDataType' 01:23:35 INFO - Running command: ['bash', '-c', 'screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'] in /builds/slave/test/build 01:23:35 INFO - Copy/paste: bash -c "screenresolution get && screenresolution list && system_profiler SPDisplaysDataType" 01:23:35 INFO - 2015-10-30 01:23:35.990 screenresolution[1687:12661] starting screenresolution argv=screenresolution get 01:23:35 INFO - 2015-10-30 01:23:35.993 screenresolution[1687:12661] Display 0: 1600x1200x32@60 01:23:36 INFO - 2015-10-30 01:23:35.999 screenresolution[1688:12663] starting screenresolution argv=screenresolution list 01:23:36 INFO - Available Modes on Display 0 01:23:36 INFO - 1600x1200x32@60 1152x870x32@75 1280x1024x32@75 01:23:36 INFO - 1024x768x32@75 1024x768x32@70 1024x768x32@60 01:23:36 INFO - 800x600x32@75 800x600x32@60 640x480x32@75 01:23:36 INFO - 640x480x32@60 1280x1024x32@60 1280x960x32@60 01:23:36 INFO - 1280x960x32@75 1344x1008x32@60 Graphics/Displays: 01:23:36 INFO - Intel HD Graphics 3000: 01:23:36 INFO - Chipset Model: Intel HD Graphics 3000 01:23:36 INFO - Type: GPU 01:23:36 INFO - Bus: Built-In 01:23:36 INFO - VRAM (Total): 512 MB 01:23:36 INFO - VRAM (Dynamic, Max): 10 01:23:36 INFO - Vendor: Intel (0x8086) 01:23:36 INFO - Device ID: 0x0116 01:23:36 INFO - Revision ID: 0x0009 01:23:36 INFO - Displays: 01:23:36 INFO - Display: 01:23:36 INFO - Resolution: 1600 x 1200 @ 60 Hz 01:23:36 INFO - Pixel Depth: 32-Bit Color (ARGB8888) 01:23:36 INFO - Display Serial Number: 1600x1200 60 01:23:36 INFO - Main Display: Yes 01:23:36 INFO - Mirror: Off 01:23:36 INFO - Online: Yes 01:23:36 INFO - Rotation: Supported 01:23:36 INFO - Return code: 0 01:23:36 INFO - Running post-action listener: _resource_record_post_action 01:23:36 INFO - Running post-run listener: _resource_record_post_run 01:23:37 INFO - Total resource usage - Wall time: 298s; CPU: 29.0%; Read bytes: 39330816; Write bytes: 584681472; Read time: 4212; Write time: 33755 01:23:37 INFO - install - Wall time: 39s; CPU: 30.0%; Read bytes: 330840576; Write bytes: 324933632; Read time: 33946; Write time: 14436 01:23:37 INFO - run-tests - Wall time: 261s; CPU: 29.0%; Read bytes: 37143552; Write bytes: 246747136; Read time: 3846; Write time: 18556 01:23:37 INFO - Running post-run listener: _upload_blobber_files 01:23:37 INFO - Blob upload gear active. 01:23:37 INFO - There are no files to upload in the directory. Skipping the blob upload mechanism ... 01:23:37 INFO - Copying logs to upload dir... 01:23:37 INFO - mkdir: /builds/slave/test/build/upload/logs program finished with exit code 0 elapsedTime=365.083027 ========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 6 mins, 6 secs) (at 2015-10-30 01:23:39.198862) ========= ========= Started set props: build_url (results: 0, elapsed: 0 secs) (at 2015-10-30 01:23:39.202847) ========= 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.GdR3T8lx2O/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.Xo8SBI494k/Listeners TMPDIR=/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.dmg program finished with exit code 0 elapsedTime=0.010013 build_url: 'https://queue.taskcluster.net/v1/task/ABAo7jDqTWuAgTn-8mWfTg/artifacts/public/build/firefox-43.0a2.en-US.mac.dmg' ========= Finished set props: build_url (results: 0, elapsed: 0 secs) (at 2015-10-30 01:23:39.260152) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:23:39.260467) ========= 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.GdR3T8lx2O/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.Xo8SBI494k/Listeners TMPDIR=/var/folders/_8/2lqr7c5x071f9gmmkyvxp58w00000w/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.005375 ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:23:39.310274) ========= ========= Started reboot slave lost (results: 0, elapsed: 7 secs) (at 2015-10-30 01:23:39.310593) ========= ========= Finished reboot slave lost (results: 0, elapsed: 7 secs) (at 2015-10-30 01:23:46.357961) =========