builder: mozilla-aurora_ubuntu64_hw_test-other-pgo slave: talos-linux64-ix-041 starttime: 1446193090.68 results: success (0) buildid: 20151029014646 builduid: e2197d6fa76745edba8eadefeb37f684 revision: 41fdefd640f368bccdeafe6446d42c0a5ad22797 ========= Started set props: master (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:10.675718) ========= master: http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/ ========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:10.676147) ========= ========= Started set props: basedir (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:10.676432) ========= bash -c pwd in dir /builds/slave/test-pgo/. (timeout 1200 secs) watching logfiles {} argv: ['bash', '-c', 'pwd'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PWD=/builds/slave/test-pgo SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False /builds/slave/test-pgo program finished with exit code 0 elapsedTime=0.005712 basedir: '/builds/slave/test-pgo' ========= Finished set props: basedir (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:10.775541) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:10.775825) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:10.817992) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:10.818340) ========= rm -rf properties in dir /builds/slave/test-pgo/. (timeout 1200 secs) watching logfiles {} argv: ['rm', '-rf', 'properties'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PWD=/builds/slave/test-pgo SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.027882 ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:10.865602) ========= ========= Started set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:10.865889) ========= 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:18:10.866250) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:10.866543) ========= 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-pgo/. (timeout 1200 secs) watching logfiles {} argv: ['bash', '-c', 'wget -Oarchiver_client.py --no-check-certificate --tries=10 --waitretry=3 https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PWD=/builds/slave/test-pgo SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False --2015-10-30 01:18:11-- https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py Resolving hg.mozilla.org (hg.mozilla.org)... 63.245.215.25, 63.245.215.102 Connecting to hg.mozilla.org (hg.mozilla.org)|63.245.215.25|:443... connected. HTTP request sent, awaiting response... 200 Script output follows Length: 12141 (12K) [text/x-python] Saving to: `archiver_client.py' 0K .......... . 100% 227M=0s 2015-10-30 01:18:11 (227 MB/s) - `archiver_client.py' saved [12141/12141] program finished with exit code 0 elapsedTime=0.191593 ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:11.070638) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:11.070966) ========= rm -rf scripts in dir /builds/slave/test-pgo/. (timeout 1200 secs) watching logfiles {} argv: ['rm', '-rf', 'scripts'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PWD=/builds/slave/test-pgo SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.195883 ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:11.278285) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 1 secs) (at 2015-10-30 01:18:11.278641) ========= bash -c 'python archiver_client.py mozharness --repo releases/mozilla-aurora --rev 41fdefd640f368bccdeafe6446d42c0a5ad22797 --destination scripts --debug' in dir /builds/slave/test-pgo/. (timeout 1200 secs) watching logfiles {} argv: ['bash', '-c', u'python archiver_client.py mozharness --repo releases/mozilla-aurora --rev 41fdefd640f368bccdeafe6446d42c0a5ad22797 --destination scripts --debug'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PWD=/builds/slave/test-pgo SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 2015-10-30 01:18:11,399 truncating revision to first 12 chars 2015-10-30 01:18:11,399 Setting DEBUG logging. 2015-10-30 01:18:11,399 attempt 1/10 2015-10-30 01:18:11,399 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:18:12,430 unpacking tar archive at: mozilla-aurora-41fdefd640f3/testing/mozharness/ program finished with exit code 0 elapsedTime=1.306379 ========= Finished 'bash -c ...' (results: 0, elapsed: 1 secs) (at 2015-10-30 01:18:12.597094) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:12.597386) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:12.605226) ========= ========= Started tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-10-30 01:18:12.605494) ========= 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:18:12.605863) ========= ========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 5 mins, 7 secs) (at 2015-10-30 01:18:12.606161) ========= /tools/buildbot/bin/python scripts/scripts/talos_script.py --suite other --add-option --webServer,localhost --branch-name Mozilla-Aurora --system-bits 64 --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Mozilla-Aurora in dir /builds/slave/test-pgo/. (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/linux_config.py', '--download-symbols', 'ondemand', '--use-talos-json', '--blob-upload-branch', 'Mozilla-Aurora'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PROPERTIES_FILE=/builds/slave/test-pgo/buildprops.json PWD=/builds/slave/test-pgo SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 01:18:12 INFO - MultiFileLogger online at 20151030 01:18:12 in /builds/slave/test-pgo 01:18:12 INFO - Run as scripts/scripts/talos_script.py --suite other --add-option --webServer,localhost --branch-name Mozilla-Aurora --system-bits 64 --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Mozilla-Aurora 01:18:12 INFO - Guessing talos json url... 01:18:12 INFO - Using buildbot properties: 01:18:12 INFO - { 01:18:12 INFO - "properties": { 01:18:12 INFO - "buildnumber": 12, 01:18:12 INFO - "product": "firefox", 01:18:12 INFO - "script_repo_revision": "production", 01:18:12 INFO - "builddir": "mozilla-aurora_ubuntu64_hw_test-other", 01:18:12 INFO - "repository": "", 01:18:12 INFO - "buildername": "Ubuntu HW 12.04 x64 mozilla-aurora pgo talos other", 01:18:12 INFO - "buildid": "20151029014646", 01:18:12 INFO - "slavename": "talos-linux64-ix-041", 01:18:12 INFO - "pgo_build": "True", 01:18:12 INFO - "basedir": "/builds/slave/test-pgo", 01:18:12 INFO - "project": "", 01:18:12 INFO - "platform": "ubuntu64_hw", 01:18:12 INFO - "master": "http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/", 01:18:12 INFO - "slavebuilddir": "test", 01:18:12 INFO - "scheduler": "tests-mozilla-aurora-linux64-pgo-talos", 01:18:12 INFO - "branch": "mozilla-aurora", 01:18:12 INFO - "repo_path": "releases/mozilla-aurora", 01:18:12 INFO - "stage_platform": "linux64-pgo", 01:18:12 INFO - "builduid": "e2197d6fa76745edba8eadefeb37f684", 01:18:12 INFO - "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797" 01:18:12 INFO - }, 01:18:12 INFO - "sourcestamp": { 01:18:12 INFO - "repository": "", 01:18:12 INFO - "hasPatch": false, 01:18:12 INFO - "project": "", 01:18:12 INFO - "branch": "mozilla-aurora-linux64-pgo-talos", 01:18:12 INFO - "changes": [ 01:18:12 INFO - { 01:18:12 INFO - "category": null, 01:18:12 INFO - "files": [ 01:18:12 INFO - { 01:18:12 INFO - "url": null, 01:18:12 INFO - "name": "https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2" 01:18:12 INFO - } 01:18:12 INFO - ], 01:18:12 INFO - "repository": "", 01:18:12 INFO - "rev": "41fdefd640f368bccdeafe6446d42c0a5ad22797", 01:18:12 INFO - "who": "jyavenard@mozilla.com", 01:18:12 INFO - "when": 1446116590, 01:18:12 INFO - "number": 6592947, 01:18:12 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:18:12 INFO - "project": "", 01:18:12 INFO - "at": "Thu 29 Oct 2015 04:03:10", 01:18:12 INFO - "branch": "mozilla-aurora-linux64-pgo-talos", 01:18:12 INFO - "revlink": "", 01:18:12 INFO - "properties": [ 01:18:12 INFO - [ 01:18:12 INFO - "buildid", 01:18:12 INFO - "20151029014646", 01:18:12 INFO - "Change" 01:18:12 INFO - ], 01:18:12 INFO - [ 01:18:12 INFO - "builduid", 01:18:12 INFO - "e2197d6fa76745edba8eadefeb37f684", 01:18:12 INFO - "Change" 01:18:12 INFO - ], 01:18:12 INFO - [ 01:18:12 INFO - "pgo_build", 01:18:12 INFO - "True", 01:18:12 INFO - "Change" 01:18:12 INFO - ] 01:18:12 INFO - ], 01:18:12 INFO - "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797" 01:18:12 INFO - } 01:18:12 INFO - ], 01:18:12 INFO - "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797" 01:18:12 INFO - } 01:18:12 INFO - } 01:18:12 INFO - Found installer url https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2. 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 - https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.txt matches https://queue.taskcluster.net 01:18:12 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.txt 01:18:12 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.txt 01:18:12 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.txt to /builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.txt 01:18:12 INFO - retry: Calling _download_file with args: ('http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.txt', '/builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.txt'), kwargs: {}, attempt #1 01:18:23 INFO - Downloaded 107 bytes. 01:18:23 INFO - Reading from file /builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.txt 01:18:23 INFO - Contents: 01:18:23 INFO - 20151029014646 01:18:23 INFO - https://hg.mozilla.org/releases/mozilla-aurora/rev/41fdefd640f368bccdeafe6446d42c0a5ad22797 01:18:23 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:23 INFO - trying https://hg.mozilla.org/releases/mozilla-aurora/raw-file/41fdefd640/testing/talos/talos.json 01:18:23 INFO - Downloading https://hg.mozilla.org/releases/mozilla-aurora/raw-file/41fdefd640/testing/talos/talos.json to /builds/slave/test-pgo/build/talos.json 01:18:23 INFO - retry: Calling _download_file with args: ('https://hg.mozilla.org/releases/mozilla-aurora/raw-file/41fdefd640/testing/talos/talos.json', '/builds/slave/test-pgo/build/talos.json'), kwargs: {}, attempt #1 01:18:23 INFO - Downloaded 6818 bytes. 01:18:24 INFO - {'extra_options': {'android': ['--apkPath=%(apk_path)s']}, 01:18:24 INFO - 'mobile-suites': {'remote-tp4m_nochrome': {'tests': ['tp4m']}, 01:18:24 INFO - 'remote-trobocheck2': {'talos_options': ['--fennecIDs', 01:18:24 INFO - '../fennec_ids.txt'], 01:18:24 INFO - 'tests': ['tcheck2']}, 01:18:24 INFO - 'remote-tsvgx': {'talos_options': ['--noChrome', 01:18:24 INFO - '--tppagecycles', 01:18:24 INFO - '7'], 01:18:24 INFO - 'tests': ['tsvgm']}}, 01:18:24 INFO - 'suites': {'chromez': {'tests': ['tresize', 'tcanvasmark']}, 01:18:24 INFO - 'chromez-e10s': {'talos_options': ['--e10s'], 01:18:24 INFO - 'tests': ['tresize', 'tcanvasmark']}, 01:18:24 INFO - 'dromaeojs': {'tests': ['dromaeo_css', 'kraken', 'v8_7']}, 01:18:24 INFO - 'dromaeojs-e10s': {'talos_options': ['--e10s'], 01:18:24 INFO - 'tests': ['dromaeo_css', 'kraken', 'v8_7']}, 01:18:24 INFO - 'g1': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5o.manifest', 01:18:24 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/', 01:18:24 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 01:18:24 INFO - 'plugins': {'32': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash32_10_3_183_5.zip', 01:18:24 INFO - '64': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash64_11_0_d1_98.zip'}, 01:18:24 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 01:18:24 INFO - 'g1-e10s': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5o.manifest', 01:18:24 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/', 01:18:24 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 01:18:24 INFO - 'plugins': {'32': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash32_10_3_183_5.zip', 01:18:24 INFO - '64': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash64_11_0_d1_98.zip'}, 01:18:24 INFO - 'talos_options': ['--e10s'], 01:18:24 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 01:18:24 INFO - 'g2': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5o.manifest', 01:18:24 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/', 01:18:24 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 01:18:24 INFO - 'tests': ['damp', 'tps']}, 01:18:24 INFO - 'g2-e10s': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5o.manifest', 01:18:24 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/', 01:18:24 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 01:18:24 INFO - 'talos_options': ['--e10s'], 01:18:24 INFO - 'tests': ['damp', 'tps']}, 01:18:24 INFO - 'g3': {'tests': ['dromaeo_dom']}, 01:18:24 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']}, 01:18:24 INFO - 'other': {'tests': ['a11yr', 01:18:24 INFO - 'ts_paint', 01:18:24 INFO - 'tpaint', 01:18:24 INFO - 'sessionrestore', 01:18:24 INFO - 'sessionrestore_no_auto_restore']}, 01:18:24 INFO - 'other-e10s': {'talos_options': ['--e10s'], 01:18:24 INFO - 'tests': ['a11yr', 01:18:24 INFO - 'ts_paint', 01:18:24 INFO - 'tpaint', 01:18:24 INFO - 'sessionrestore', 01:18:24 INFO - 'sessionrestore_no_auto_restore']}, 01:18:24 INFO - 'other-e10s_l64': {'talos_options': ['--e10s'], 01:18:24 INFO - 'tests': ['a11yr', 01:18:24 INFO - 'ts_paint', 01:18:24 INFO - 'tpaint', 01:18:24 INFO - 'sessionrestore', 01:18:24 INFO - 'sessionrestore_no_auto_restore']}, 01:18:24 INFO - 'other-e10s_nol64': {'talos_options': ['--e10s'], 01:18:24 INFO - 'tests': ['a11yr', 01:18:24 INFO - 'ts_paint', 01:18:24 INFO - 'tpaint', 01:18:24 INFO - 'sessionrestore', 01:18:24 INFO - 'sessionrestore_no_auto_restore']}, 01:18:24 INFO - 'other_l64': {'tests': ['a11yr', 01:18:24 INFO - 'ts_paint', 01:18:24 INFO - 'tpaint', 01:18:24 INFO - 'sessionrestore', 01:18:24 INFO - 'sessionrestore_no_auto_restore']}, 01:18:24 INFO - 'other_nol64': {'tests': ['a11yr', 01:18:24 INFO - 'ts_paint', 01:18:24 INFO - 'tpaint', 01:18:24 INFO - 'sessionrestore', 01:18:24 INFO - 'sessionrestore_no_auto_restore']}, 01:18:24 INFO - 'svgr': {'tests': ['tsvgx', 01:18:24 INFO - 'tsvgr_opacity', 01:18:24 INFO - 'tart', 01:18:24 INFO - 'tscrollx', 01:18:24 INFO - 'cart']}, 01:18:24 INFO - 'svgr-e10s': {'talos_options': ['--e10s'], 01:18:24 INFO - 'tests': ['tsvgx', 01:18:24 INFO - 'tsvgr_opacity', 01:18:24 INFO - 'tart', 01:18:24 INFO - 'tscrollx', 01:18:24 INFO - 'cart']}, 01:18:24 INFO - 'tp5o': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5o.manifest', 01:18:24 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/', 01:18:24 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 01:18:24 INFO - 'plugins': {'32': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash32_10_3_183_5.zip', 01:18:24 INFO - '64': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash64_11_0_d1_98.zip'}, 01:18:24 INFO - 'tests': ['tp5o']}, 01:18:24 INFO - 'tp5o-e10s': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5o.manifest', 01:18:24 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/', 01:18:24 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 01:18:24 INFO - 'plugins': {'32': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash32_10_3_183_5.zip', 01:18:24 INFO - '64': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash64_11_0_d1_98.zip'}, 01:18:24 INFO - 'talos_options': ['--e10s'], 01:18:24 INFO - 'tests': ['tp5o']}, 01:18:24 INFO - 'xperf': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5n.manifest', 01:18:24 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/', 01:18:24 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 01:18:24 INFO - 'plugins': {'32': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash32_10_3_183_5.zip', 01:18:24 INFO - '64': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash64_11_0_d1_98.zip'}, 01:18:24 INFO - 'talos_options': ['--xperf_path', 01:18:24 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 01:18:24 INFO - 'tests': ['tp5n']}, 01:18:24 INFO - 'xperf-e10s': {'pagesets_manifest_path': 'talos/page_load_test/tp5n/tp5n.manifest', 01:18:24 INFO - 'pagesets_parent_dir_path': 'talos/page_load_test/', 01:18:24 INFO - 'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 01:18:24 INFO - 'plugins': {'32': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash32_10_3_183_5.zip', 01:18:24 INFO - '64': 'http://talos-bundles.pvt.build.mozilla.org/zips/flash64_11_0_d1_98.zip'}, 01:18:24 INFO - 'talos_options': ['--e10s', 01:18:24 INFO - '--xperf_path', 01:18:24 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"', 01:18:24 INFO - 'C:/slave/talos-data/talos/xperf.config'], 01:18:24 INFO - 'tests': ['tp5n']}}, 01:18:24 INFO - 'talos.zip': {'path': '', 01:18:24 INFO - 'url': 'http://talos-bundles.pvt.build.mozilla.org/zips/talos.a6052c33d420.zip'}} 01:18:24 INFO - Dumping config to /builds/slave/test-pgo/logs/localconfig.json. 01:18:24 INFO - {'append_to_log': False, 01:18:24 INFO - 'base_work_dir': '/builds/slave/test-pgo', 01:18:24 INFO - 'blob_upload_branch': 'Mozilla-Aurora', 01:18:24 INFO - 'blob_uploader_auth_file': '/builds/slave/test-pgo/oauth.txt', 01:18:24 INFO - 'branch': 'Mozilla-Aurora', 01:18:24 INFO - 'buildbot_json_path': 'buildprops.json', 01:18:24 INFO - 'config_files': ('talos/linux_config.py',), 01:18:24 INFO - 'default_actions': ('clobber', 01:18:24 INFO - 'read-buildbot-config', 01:18:24 INFO - 'download-and-extract', 01:18:24 INFO - 'populate-webroot', 01:18:24 INFO - 'create-virtualenv', 01:18:24 INFO - 'install', 01:18:24 INFO - 'run-tests'), 01:18:24 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 01:18:24 INFO - 'download_minidump_stackwalk': True, 01:18:24 INFO - 'download_symbols': 'ondemand', 01:18:24 INFO - 'exes': {'python': '/tools/buildbot/bin/python', 01:18:24 INFO - 'tooltool.py': '/tools/tooltool.py', 01:18:24 INFO - 'virtualenv': ('/tools/buildbot/bin/python', 01:18:24 INFO - '/tools/misc-python/virtualenv.py')}, 01:18:24 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 01:18:24 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 01:18:24 INFO - 'installer_path': 'installer.exe', 01:18:24 INFO - 'log_level': 'info', 01:18:24 INFO - 'log_name': 'talos', 01:18:24 INFO - 'log_to_console': True, 01:18:24 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk', 01:18:24 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest', 01:18:24 INFO - 'opt_config_files': (), 01:18:24 INFO - 'pip_index': False, 01:18:24 INFO - 'python_webserver': False, 01:18:24 INFO - 'sps_profile': False, 01:18:24 INFO - 'sps_profile_interval': 0, 01:18:24 INFO - 'suite': 'other', 01:18:24 INFO - 'system_bits': '64', 01:18:24 INFO - 'talos_extra_options': ('--webServer', 'localhost'), 01:18:24 INFO - 'talos_url': 'https://hg.mozilla.org/build/talos/archive/tip.tar.gz', 01:18:24 INFO - 'tests': (), 01:18:24 INFO - 'title': 'talos-linux64-ix-041', 01:18:24 INFO - 'tooltool_cache': '/builds/tooltool_cache', 01:18:24 INFO - 'use_talos_json': True, 01:18:24 INFO - 'virtualenv_path': '/builds/slave/test-pgo/build/venv', 01:18:24 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 01:18:24 INFO - 'webroot': '/builds/slave/test-pgo/../talos-data', 01:18:24 INFO - 'work_dir': 'build'} 01:18:24 INFO - ##### 01:18:24 INFO - ##### Running clobber step. 01:18:24 INFO - ##### 01:18:24 INFO - Running pre-action listener: _resource_record_pre_action 01:18:24 INFO - Running main action method: clobber 01:18:24 INFO - rmtree: /builds/slave/test-pgo/build 01:18:24 INFO - retry: Calling rmtree with args: ('/builds/slave/test-pgo/build',), kwargs: {}, attempt #1 01:18:25 INFO - Running post-action listener: _resource_record_post_action 01:18:25 INFO - ##### 01:18:25 INFO - ##### Running read-buildbot-config step. 01:18:25 INFO - ##### 01:18:25 INFO - Running pre-action listener: _resource_record_pre_action 01:18:25 INFO - Running main action method: read_buildbot_config 01:18:25 INFO - Using buildbot properties: 01:18:25 INFO - { 01:18:25 INFO - "properties": { 01:18:25 INFO - "buildnumber": 12, 01:18:25 INFO - "product": "firefox", 01:18:25 INFO - "script_repo_revision": "production", 01:18:25 INFO - "builddir": "mozilla-aurora_ubuntu64_hw_test-other", 01:18:25 INFO - "repository": "", 01:18:25 INFO - "buildername": "Ubuntu HW 12.04 x64 mozilla-aurora pgo talos other", 01:18:25 INFO - "buildid": "20151029014646", 01:18:25 INFO - "slavename": "talos-linux64-ix-041", 01:18:25 INFO - "pgo_build": "True", 01:18:25 INFO - "basedir": "/builds/slave/test-pgo", 01:18:25 INFO - "project": "", 01:18:25 INFO - "platform": "ubuntu64_hw", 01:18:25 INFO - "master": "http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/", 01:18:25 INFO - "slavebuilddir": "test", 01:18:25 INFO - "scheduler": "tests-mozilla-aurora-linux64-pgo-talos", 01:18:25 INFO - "branch": "mozilla-aurora", 01:18:25 INFO - "repo_path": "releases/mozilla-aurora", 01:18:25 INFO - "stage_platform": "linux64-pgo", 01:18:25 INFO - "builduid": "e2197d6fa76745edba8eadefeb37f684", 01:18:25 INFO - "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797" 01:18:25 INFO - }, 01:18:25 INFO - "sourcestamp": { 01:18:25 INFO - "repository": "", 01:18:25 INFO - "hasPatch": false, 01:18:25 INFO - "project": "", 01:18:25 INFO - "branch": "mozilla-aurora-linux64-pgo-talos", 01:18:25 INFO - "changes": [ 01:18:25 INFO - { 01:18:25 INFO - "category": null, 01:18:25 INFO - "files": [ 01:18:25 INFO - { 01:18:25 INFO - "url": null, 01:18:25 INFO - "name": "https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2" 01:18:25 INFO - } 01:18:25 INFO - ], 01:18:25 INFO - "repository": "", 01:18:25 INFO - "rev": "41fdefd640f368bccdeafe6446d42c0a5ad22797", 01:18:25 INFO - "who": "jyavenard@mozilla.com", 01:18:25 INFO - "when": 1446116590, 01:18:25 INFO - "number": 6592947, 01:18:25 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:18:25 INFO - "project": "", 01:18:25 INFO - "at": "Thu 29 Oct 2015 04:03:10", 01:18:25 INFO - "branch": "mozilla-aurora-linux64-pgo-talos", 01:18:25 INFO - "revlink": "", 01:18:25 INFO - "properties": [ 01:18:25 INFO - [ 01:18:25 INFO - "buildid", 01:18:25 INFO - "20151029014646", 01:18:25 INFO - "Change" 01:18:25 INFO - ], 01:18:25 INFO - [ 01:18:25 INFO - "builduid", 01:18:25 INFO - "e2197d6fa76745edba8eadefeb37f684", 01:18:25 INFO - "Change" 01:18:25 INFO - ], 01:18:25 INFO - [ 01:18:25 INFO - "pgo_build", 01:18:25 INFO - "True", 01:18:25 INFO - "Change" 01:18:25 INFO - ] 01:18:25 INFO - ], 01:18:25 INFO - "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797" 01:18:25 INFO - } 01:18:25 INFO - ], 01:18:25 INFO - "revision": "41fdefd640f368bccdeafe6446d42c0a5ad22797" 01:18:25 INFO - } 01:18:25 INFO - } 01:18:25 INFO - Running post-action listener: _resource_record_post_action 01:18:25 INFO - ##### 01:18:25 INFO - ##### Running download-and-extract step. 01:18:25 INFO - ##### 01:18:25 INFO - Running pre-action listener: _resource_record_pre_action 01:18:25 INFO - Running main action method: download_and_extract 01:18:25 INFO - mkdir: /builds/slave/test-pgo/build/tests 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 - https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/test_packages.json matches https://queue.taskcluster.net 01:18:25 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/test_packages.json 01:18:25 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/test_packages.json 01:18:25 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/test_packages.json to /builds/slave/test-pgo/build/test_packages.json 01:18:25 INFO - retry: Calling _download_file with args: ('http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/test_packages.json', '/builds/slave/test-pgo/build/test_packages.json'), kwargs: {}, attempt #1 01:18:26 INFO - Downloaded 1302 bytes. 01:18:26 INFO - Reading from file /builds/slave/test-pgo/build/test_packages.json 01:18:26 INFO - Using the following test package requirements: 01:18:26 INFO - {u'common': [u'firefox-43.0a2.en-US.linux-x86_64.common.tests.zip'], 01:18:26 INFO - u'cppunittest': [u'firefox-43.0a2.en-US.linux-x86_64.common.tests.zip', 01:18:26 INFO - u'firefox-43.0a2.en-US.linux-x86_64.cppunittest.tests.zip'], 01:18:26 INFO - u'jittest': [u'firefox-43.0a2.en-US.linux-x86_64.common.tests.zip', 01:18:26 INFO - u'jsshell-linux-x86_64.zip'], 01:18:26 INFO - u'mochitest': [u'firefox-43.0a2.en-US.linux-x86_64.common.tests.zip', 01:18:26 INFO - u'firefox-43.0a2.en-US.linux-x86_64.mochitest.tests.zip'], 01:18:26 INFO - u'mozbase': [u'firefox-43.0a2.en-US.linux-x86_64.common.tests.zip'], 01:18:26 INFO - u'reftest': [u'firefox-43.0a2.en-US.linux-x86_64.common.tests.zip', 01:18:26 INFO - u'firefox-43.0a2.en-US.linux-x86_64.reftest.tests.zip'], 01:18:26 INFO - u'talos': [u'firefox-43.0a2.en-US.linux-x86_64.common.tests.zip', 01:18:26 INFO - u'firefox-43.0a2.en-US.linux-x86_64.talos.tests.zip'], 01:18:26 INFO - u'web-platform': [u'firefox-43.0a2.en-US.linux-x86_64.common.tests.zip', 01:18:26 INFO - u'firefox-43.0a2.en-US.linux-x86_64.web-platform.tests.zip'], 01:18:26 INFO - u'webapprt': [u'firefox-43.0a2.en-US.linux-x86_64.common.tests.zip'], 01:18:26 INFO - u'xpcshell': [u'firefox-43.0a2.en-US.linux-x86_64.common.tests.zip', 01:18:26 INFO - u'firefox-43.0a2.en-US.linux-x86_64.xpcshell.tests.zip']} 01:18:26 INFO - Downloading packages: [u'firefox-43.0a2.en-US.linux-x86_64.common.tests.zip'] for test suite category: common 01:18:26 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:18:26 INFO - https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip matches https://queue.taskcluster.net 01:18:26 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip 01:18:26 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip 01:18:26 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip to /builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip 01:18:26 INFO - retry: Calling _download_file with args: (u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip', u'/builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip'), kwargs: {}, attempt #1 01:18:37 INFO - Downloaded 22907380 bytes. 01:18:37 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip'] in /builds/slave/test-pgo/build/tests 01:18:37 INFO - Copy/paste: unzip -q -o /builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip 01:18:37 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip'] with output_timeout 1760 01:18:38 INFO - Return code: 0 01:18:38 INFO - Downloading packages: [u'firefox-43.0a2.en-US.linux-x86_64.common.tests.zip', u'firefox-43.0a2.en-US.linux-x86_64.talos.tests.zip'] for test suite category: talos 01:18: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:18:38 INFO - https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip matches https://queue.taskcluster.net 01:18:38 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip 01:18:38 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip 01:18:38 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip to /builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip 01:18:38 INFO - retry: Calling _download_file with args: (u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip', u'/builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip'), kwargs: {}, attempt #1 01:18:39 INFO - Downloaded 22907380 bytes. 01:18:39 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip'] in /builds/slave/test-pgo/build/tests 01:18:39 INFO - Copy/paste: unzip -q -o /builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip 01:18:39 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.common.tests.zip'] with output_timeout 1760 01:18:40 INFO - Return code: 0 01:18:40 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:18:40 INFO - https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.talos.tests.zip matches https://queue.taskcluster.net 01:18:40 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.talos.tests.zip 01:18:40 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.talos.tests.zip 01:18:40 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.talos.tests.zip to /builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.talos.tests.zip 01:18:40 INFO - retry: Calling _download_file with args: (u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.talos.tests.zip', u'/builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.talos.tests.zip'), kwargs: {}, attempt #1 01:18:41 INFO - Downloaded 10881672 bytes. 01:18:41 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.talos.tests.zip'] in /builds/slave/test-pgo/build/tests 01:18:41 INFO - Copy/paste: unzip -q -o /builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.talos.tests.zip 01:18:41 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.talos.tests.zip'] with output_timeout 1760 01:18:42 INFO - Return code: 0 01:18:42 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:18:42 INFO - https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2 matches https://queue.taskcluster.net 01:18:42 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2 01:18:42 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2 01:18:42 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2 to /builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2 01:18:42 INFO - retry: Calling _download_file with args: ('http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2', '/builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2'), kwargs: {}, attempt #1 01:18:44 INFO - Downloaded 56990127 bytes. 01:18:44 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2 01:18:44 INFO - mkdir: /builds/slave/test-pgo/properties 01:18:44 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test-pgo/properties/build_url 01:18:44 INFO - Writing to file /builds/slave/test-pgo/properties/build_url 01:18:44 INFO - Contents: 01:18:44 INFO - build_url:https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2 01:18:44 INFO - Running post-action listener: _resource_record_post_action 01:18:44 INFO - Running post-action listener: _set_extra_try_arguments 01:18:44 INFO - ##### 01:18:44 INFO - ##### Running populate-webroot step. 01:18:44 INFO - ##### 01:18:44 INFO - Running pre-action listener: _resource_record_pre_action 01:18:44 INFO - Running main action method: populate_webroot 01:18:44 INFO - Populating webroot /builds/slave/test-pgo/../talos-data... 01:18:44 INFO - rmtree: /builds/slave/test-pgo/../talos-data/talos 01:18:44 INFO - retry: Calling rmtree with args: ('/builds/slave/test-pgo/../talos-data/talos',), kwargs: {}, attempt #1 01:18:49 INFO - copying tree: /builds/slave/test-pgo/build/tests/talos/talos to /builds/slave/test-pgo/../talos-data/talos 01:18:49 INFO - rmtree: /builds/slave/test-pgo/../talos-data/talos 01:18:49 INFO - Running post-action listener: _resource_record_post_action 01:18:49 INFO - ##### 01:18:49 INFO - ##### Running create-virtualenv step. 01:18:49 INFO - ##### 01:18:49 INFO - Running pre-action listener: _resource_record_pre_action 01:18:49 INFO - Running main action method: create_virtualenv 01:18:49 INFO - Creating virtualenv /builds/slave/test-pgo/build/venv 01:18:49 INFO - Running command: ['/tools/buildbot/bin/python', '/tools/misc-python/virtualenv.py', '--no-site-packages', '--distribute', '/builds/slave/test-pgo/build/venv'] in /builds/slave/test-pgo/build 01:18:49 INFO - Copy/paste: /tools/buildbot/bin/python /tools/misc-python/virtualenv.py --no-site-packages --distribute /builds/slave/test-pgo/build/venv 01:18:49 INFO - The --no-site-packages flag is deprecated; it is now the default behavior. 01:18:49 INFO - Using real prefix '/usr' 01:18:49 INFO - New python executable in /builds/slave/test-pgo/build/venv/bin/python 01:18:50 INFO - Installing distribute.............................................................................................................................................................................................done. 01:18:52 INFO - Installing pip.................done. 01:18:52 INFO - Return code: 0 01:18:52 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test-pgo/build/venv 01:18:52 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:18:52 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 01:18:52 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:18:52 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:18:52 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 01:18:52 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:18:52 INFO - retry: Calling run_command with args: [['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test-pgo/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 0x7f6bc51ddb90>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1a267b0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1aeb4a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x187dbf0>, '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 0x1b7b4f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b7b9a0>, 'level': 'critical'}], 'cwd': '/builds/slave/test-pgo/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test-pgo', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 01:18:52 INFO - Running command: ['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test-pgo/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-pgo/build 01:18:52 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/pip install --download-cache /builds/slave/test-pgo/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:52 INFO - Using env: {'DISPLAY': ':0', 01:18:52 INFO - 'HOME': '/home/cltbld', 01:18:52 INFO - 'LANG': 'en_US.UTF-8', 01:18:52 INFO - 'LANGUAGE': 'en_US:en', 01:18:52 INFO - 'LOGNAME': 'cltbld', 01:18:52 INFO - 'MAIL': '/var/mail/cltbld', 01:18:52 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 01:18:52 INFO - 'MOZ_NO_REMOTE': '1', 01:18:52 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 01:18:52 INFO - 'NO_EM_RESTART': '1', 01:18:52 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 01:18:52 INFO - 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json', 01:18:52 INFO - 'PWD': '/builds/slave/test-pgo', 01:18:52 INFO - 'SHELL': '/bin/bash', 01:18:52 INFO - 'SHLVL': '1', 01:18:52 INFO - 'TERM': 'linux', 01:18:52 INFO - 'TMOUT': '86400', 01:18:52 INFO - 'USER': 'cltbld', 01:18:52 INFO - 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661', 01:18:52 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 01:18:52 INFO - '_': '/tools/buildbot/bin/python'} 01:18:52 INFO - Ignoring indexes: https://pypi.python.org/simple/ 01:18:52 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:52 INFO - Cleaning up... 01:18:52 INFO - Return code: 0 01:18:52 INFO - Installing psutil>=0.7.1 into virtualenv /builds/slave/test-pgo/build/venv 01:18:52 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:18:52 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 01:18:52 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:18:52 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:18:52 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 01:18:52 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:18:52 INFO - retry: Calling run_command with args: [['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test-pgo/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 0x7f6bc51ddb90>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1a267b0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1aeb4a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x187dbf0>, '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 0x1b7b4f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b7b9a0>, 'level': 'critical'}], 'cwd': '/builds/slave/test-pgo/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test-pgo', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 01:18:52 INFO - Running command: ['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test-pgo/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-pgo/build 01:18:52 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/pip install --download-cache /builds/slave/test-pgo/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:52 INFO - Using env: {'DISPLAY': ':0', 01:18:52 INFO - 'HOME': '/home/cltbld', 01:18:52 INFO - 'LANG': 'en_US.UTF-8', 01:18:52 INFO - 'LANGUAGE': 'en_US:en', 01:18:52 INFO - 'LOGNAME': 'cltbld', 01:18:52 INFO - 'MAIL': '/var/mail/cltbld', 01:18:52 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 01:18:52 INFO - 'MOZ_NO_REMOTE': '1', 01:18:52 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 01:18:52 INFO - 'NO_EM_RESTART': '1', 01:18:52 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 01:18:52 INFO - 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json', 01:18:52 INFO - 'PWD': '/builds/slave/test-pgo', 01:18:52 INFO - 'SHELL': '/bin/bash', 01:18:52 INFO - 'SHLVL': '1', 01:18:52 INFO - 'TERM': 'linux', 01:18:52 INFO - 'TMOUT': '86400', 01:18:52 INFO - 'USER': 'cltbld', 01:18:52 INFO - 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661', 01:18:52 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 01:18:52 INFO - '_': '/tools/buildbot/bin/python'} 01:18:53 INFO - Ignoring indexes: https://pypi.python.org/simple/ 01:18:53 INFO - Downloading/unpacking psutil>=0.7.1 01:18:53 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:53 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:53 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:53 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:53 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:53 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:54 INFO - Creating supposed download cache at /builds/slave/test-pgo/build/venv/cache 01:18:54 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:54 INFO - Running setup.py (path:/builds/slave/test-pgo/build/venv/build/psutil/setup.py) egg_info for package psutil 01:18:54 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 01:18:54 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 01:18:54 INFO - Installing collected packages: psutil 01:18:54 INFO - Running setup.py install for psutil 01:18:54 INFO - building 'psutil._psutil_linux' extension 01:18:54 INFO - gcc -pthread -fno-strict-aliasing -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -fPIC -DPSUTIL_VERSION=311 -I/usr/include/python2.7 -c psutil/_psutil_linux.c -o build/temp.linux-x86_64-2.7/psutil/_psutil_linux.o 01:18:55 INFO - gcc -pthread -shared -Wl,-O1 -Wl,-Bsymbolic-functions -Wl,-Bsymbolic-functions -Wl,-z,relro build/temp.linux-x86_64-2.7/psutil/_psutil_linux.o -o build/lib.linux-x86_64-2.7/psutil/_psutil_linux.so 01:18:56 INFO - building 'psutil._psutil_posix' extension 01:18:56 INFO - gcc -pthread -fno-strict-aliasing -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -fPIC -I/usr/include/python2.7 -c psutil/_psutil_posix.c -o build/temp.linux-x86_64-2.7/psutil/_psutil_posix.o 01:18:56 INFO - gcc -pthread -shared -Wl,-O1 -Wl,-Bsymbolic-functions -Wl,-Bsymbolic-functions -Wl,-z,relro build/temp.linux-x86_64-2.7/psutil/_psutil_posix.o -o build/lib.linux-x86_64-2.7/psutil/_psutil_posix.so 01:18:56 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 01:18:56 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 01:18:56 INFO - Successfully installed psutil 01:18:56 INFO - Cleaning up... 01:18:56 INFO - Return code: 0 01:18:56 INFO - Installing mozsystemmonitor==0.0.0 into virtualenv /builds/slave/test-pgo/build/venv 01:18:56 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:56 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 01:18:56 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:18:56 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:56 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 01:18:56 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:18:56 INFO - retry: Calling run_command with args: [['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test-pgo/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 0x7f6bc51ddb90>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1a267b0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1aeb4a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x187dbf0>, '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 0x1b7b4f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b7b9a0>, 'level': 'critical'}], 'cwd': '/builds/slave/test-pgo/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test-pgo', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 01:18:56 INFO - Running command: ['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test-pgo/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-pgo/build 01:18:56 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/pip install --download-cache /builds/slave/test-pgo/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:56 INFO - Using env: {'DISPLAY': ':0', 01:18:56 INFO - 'HOME': '/home/cltbld', 01:18:56 INFO - 'LANG': 'en_US.UTF-8', 01:18:56 INFO - 'LANGUAGE': 'en_US:en', 01:18:56 INFO - 'LOGNAME': 'cltbld', 01:18:56 INFO - 'MAIL': '/var/mail/cltbld', 01:18:56 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 01:18:56 INFO - 'MOZ_NO_REMOTE': '1', 01:18:56 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 01:18:56 INFO - 'NO_EM_RESTART': '1', 01:18:56 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 01:18:56 INFO - 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json', 01:18:56 INFO - 'PWD': '/builds/slave/test-pgo', 01:18:56 INFO - 'SHELL': '/bin/bash', 01:18:56 INFO - 'SHLVL': '1', 01:18:56 INFO - 'TERM': 'linux', 01:18:56 INFO - 'TMOUT': '86400', 01:18:56 INFO - 'USER': 'cltbld', 01:18:56 INFO - 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661', 01:18:56 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 01:18:56 INFO - '_': '/tools/buildbot/bin/python'} 01:18:56 INFO - Ignoring indexes: https://pypi.python.org/simple/ 01:18:56 INFO - Downloading/unpacking mozsystemmonitor==0.0.0 01:18:56 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 01:18:56 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 01:18:56 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 01:18:56 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 01:18:56 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 01:18:56 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 01:18:58 INFO - Downloading mozsystemmonitor-0.0.tar.gz 01:18:58 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fmozsystemmonitor-0.0.tar.gz 01:18:58 INFO - Running setup.py (path:/builds/slave/test-pgo/build/venv/build/mozsystemmonitor/setup.py) egg_info for package mozsystemmonitor 01:18:58 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:58 INFO - Installing collected packages: mozsystemmonitor 01:18:58 INFO - Running setup.py install for mozsystemmonitor 01:18:58 INFO - Successfully installed mozsystemmonitor 01:18:58 INFO - Cleaning up... 01:18:58 INFO - Return code: 0 01:18:58 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test-pgo/build/venv 01:18:58 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:58 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 01:18:58 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:18:58 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:58 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 01:18:58 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:18:58 INFO - retry: Calling run_command with args: [['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test-pgo/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 0x7f6bc51ddb90>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1a267b0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1aeb4a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x187dbf0>, '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 0x1b7b4f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b7b9a0>, 'level': 'critical'}], 'cwd': '/builds/slave/test-pgo/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test-pgo', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 01:18:58 INFO - Running command: ['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test-pgo/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-pgo/build 01:18:58 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/pip install --download-cache /builds/slave/test-pgo/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:58 INFO - Using env: {'DISPLAY': ':0', 01:18:58 INFO - 'HOME': '/home/cltbld', 01:18:58 INFO - 'LANG': 'en_US.UTF-8', 01:18:58 INFO - 'LANGUAGE': 'en_US:en', 01:18:58 INFO - 'LOGNAME': 'cltbld', 01:18:58 INFO - 'MAIL': '/var/mail/cltbld', 01:18:58 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 01:18:58 INFO - 'MOZ_NO_REMOTE': '1', 01:18:58 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 01:18:58 INFO - 'NO_EM_RESTART': '1', 01:18:58 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 01:18:58 INFO - 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json', 01:18:58 INFO - 'PWD': '/builds/slave/test-pgo', 01:18:58 INFO - 'SHELL': '/bin/bash', 01:18:58 INFO - 'SHLVL': '1', 01:18:58 INFO - 'TERM': 'linux', 01:18:58 INFO - 'TMOUT': '86400', 01:18:58 INFO - 'USER': 'cltbld', 01:18:58 INFO - 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661', 01:18:58 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 01:18:58 INFO - '_': '/tools/buildbot/bin/python'} 01:18:58 INFO - Ignoring indexes: https://pypi.python.org/simple/ 01:18:58 INFO - Downloading/unpacking blobuploader==1.2.4 01:18:58 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:58 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:58 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:58 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:58 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:58 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:19:00 INFO - Downloading blobuploader-1.2.4.tar.gz 01:19:00 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fblobuploader-1.2.4.tar.gz 01:19:00 INFO - Running setup.py (path:/builds/slave/test-pgo/build/venv/build/blobuploader/setup.py) egg_info for package blobuploader 01:19:00 INFO - Downloading/unpacking requests==1.2.3. (from blobuploader==1.2.4) 01:19:00 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:19:00 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:19:00 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:19:00 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:19:00 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:19:00 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:19:00 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Frequests-1.2.3.tar.gz 01:19:00 INFO - Running setup.py (path:/builds/slave/test-pgo/build/venv/build/requests/setup.py) egg_info for package requests 01:19:00 INFO - Downloading/unpacking docopt==0.6.1 (from blobuploader==1.2.4) 01:19:00 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:19:00 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:19:00 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:19:00 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:19:00 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:19:00 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:19:00 INFO - Downloading docopt-0.6.1.tar.gz 01:19:00 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fdocopt-0.6.1.tar.gz 01:19:00 INFO - Running setup.py (path:/builds/slave/test-pgo/build/venv/build/docopt/setup.py) egg_info for package docopt 01:19:01 INFO - Installing collected packages: blobuploader, requests, docopt 01:19:01 INFO - Running setup.py install for blobuploader 01:19:01 INFO - changing mode of build/scripts-2.7/blobberc.py from 664 to 775 01:19:01 INFO - changing mode of /builds/slave/test-pgo/build/venv/bin/blobberc.py to 775 01:19:01 INFO - Running setup.py install for requests 01:19:01 INFO - Running setup.py install for docopt 01:19:01 INFO - Successfully installed blobuploader requests docopt 01:19:01 INFO - Cleaning up... 01:19:01 INFO - Return code: 0 01:19:01 INFO - Installing None into virtualenv /builds/slave/test-pgo/build/venv 01:19:01 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:01 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 01:19:01 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:19:01 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:01 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 01:19:01 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:19:01 INFO - retry: Calling run_command with args: [['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--no-deps', '--download-cache', '/builds/slave/test-pgo/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test-pgo/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 0x7f6bc51ddb90>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1a267b0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1aeb4a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x187dbf0>, '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 0x1b7b4f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b7b9a0>, 'level': 'critical'}], 'cwd': '/builds/slave/test-pgo/build/tests/config', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test-pgo', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 01:19:01 INFO - Running command: ['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--no-deps', '--download-cache', '/builds/slave/test-pgo/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test-pgo/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-pgo/build/tests/config 01:19:01 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/pip install --no-deps --download-cache /builds/slave/test-pgo/build/venv/cache --timeout 120 -r /builds/slave/test-pgo/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:19:01 INFO - Using env: {'DISPLAY': ':0', 01:19:01 INFO - 'HOME': '/home/cltbld', 01:19:01 INFO - 'LANG': 'en_US.UTF-8', 01:19:01 INFO - 'LANGUAGE': 'en_US:en', 01:19:01 INFO - 'LOGNAME': 'cltbld', 01:19:01 INFO - 'MAIL': '/var/mail/cltbld', 01:19:01 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 01:19:01 INFO - 'MOZ_NO_REMOTE': '1', 01:19:01 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 01:19:01 INFO - 'NO_EM_RESTART': '1', 01:19:01 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 01:19:01 INFO - 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json', 01:19:01 INFO - 'PWD': '/builds/slave/test-pgo', 01:19:01 INFO - 'SHELL': '/bin/bash', 01:19:01 INFO - 'SHLVL': '1', 01:19:01 INFO - 'TERM': 'linux', 01:19:01 INFO - 'TMOUT': '86400', 01:19:01 INFO - 'USER': 'cltbld', 01:19:01 INFO - 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661', 01:19:01 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 01:19:01 INFO - '_': '/tools/buildbot/bin/python'} 01:19:01 INFO - Ignoring indexes: https://pypi.python.org/simple/ 01:19:01 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/manifestparser 01:19:01 INFO - Running setup.py (path:/tmp/pip-yMCeYo-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/manifestparser 01:19:01 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozcrash 01:19:01 INFO - Running setup.py (path:/tmp/pip-rhzFxh-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozcrash 01:19:01 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozdebug 01:19:02 INFO - Running setup.py (path:/tmp/pip-B9IsMq-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozdebug 01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozdevice 01:19:02 INFO - Running setup.py (path:/tmp/pip-FWnsW4-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozdevice 01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozfile 01:19:02 INFO - Running setup.py (path:/tmp/pip-eObE8G-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozfile 01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozhttpd 01:19:02 INFO - Running setup.py (path:/tmp/pip-t_xBid-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozhttpd 01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozinfo 01:19:02 INFO - Running setup.py (path:/tmp/pip-RknFQf-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozinfo 01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozinstall 01:19:02 INFO - Running setup.py (path:/tmp/pip-om1db6-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozinstall 01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozleak 01:19:02 INFO - Running setup.py (path:/tmp/pip-E2qN6M-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozleak 01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozlog 01:19:02 INFO - Running setup.py (path:/tmp/pip-8XZrWX-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozlog 01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/moznetwork 01:19:02 INFO - Running setup.py (path:/tmp/pip-YsMlaA-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/moznetwork 01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozprocess 01:19:02 INFO - Running setup.py (path:/tmp/pip-sByJIb-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozprocess 01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozprofile 01:19:02 INFO - Running setup.py (path:/tmp/pip-rcIHZJ-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozprofile 01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozrunner 01:19:02 INFO - Running setup.py (path:/tmp/pip-WjHYg0-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozrunner 01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozscreenshot 01:19:02 INFO - Running setup.py (path:/tmp/pip-Aqm76F-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozscreenshot 01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/moztest 01:19:02 INFO - Running setup.py (path:/tmp/pip-x9SwlR-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/moztest 01:19:02 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozversion 01:19:03 INFO - Running setup.py (path:/tmp/pip-GHLuYA-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozversion 01:19:03 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion 01:19:03 INFO - Running setup.py install for manifestparser 01:19:03 INFO - Installing manifestparser script to /builds/slave/test-pgo/build/venv/bin 01:19:03 INFO - Running setup.py install for mozcrash 01:19:03 INFO - Running setup.py install for mozdebug 01:19:03 INFO - Running setup.py install for mozdevice 01:19:03 INFO - Installing sutini script to /builds/slave/test-pgo/build/venv/bin 01:19:03 INFO - Installing dm script to /builds/slave/test-pgo/build/venv/bin 01:19:03 INFO - Running setup.py install for mozfile 01:19:03 INFO - Running setup.py install for mozhttpd 01:19:03 INFO - Installing mozhttpd script to /builds/slave/test-pgo/build/venv/bin 01:19:03 INFO - Running setup.py install for mozinfo 01:19:03 INFO - Installing mozinfo script to /builds/slave/test-pgo/build/venv/bin 01:19:03 INFO - Running setup.py install for mozInstall 01:19:03 INFO - Installing moz_remove_from_system script to /builds/slave/test-pgo/build/venv/bin 01:19:03 INFO - Installing mozuninstall script to /builds/slave/test-pgo/build/venv/bin 01:19:03 INFO - Installing mozinstall script to /builds/slave/test-pgo/build/venv/bin 01:19:03 INFO - Installing moz_add_to_system script to /builds/slave/test-pgo/build/venv/bin 01:19:03 INFO - Running setup.py install for mozleak 01:19:03 INFO - Running setup.py install for mozlog 01:19:04 INFO - Installing structlog script to /builds/slave/test-pgo/build/venv/bin 01:19:04 INFO - Running setup.py install for moznetwork 01:19:04 INFO - Installing moznetwork script to /builds/slave/test-pgo/build/venv/bin 01:19:04 INFO - Running setup.py install for mozprocess 01:19:04 INFO - Running setup.py install for mozprofile 01:19:04 INFO - Installing mozprofile script to /builds/slave/test-pgo/build/venv/bin 01:19:04 INFO - Installing diff-profiles script to /builds/slave/test-pgo/build/venv/bin 01:19:04 INFO - Installing view-profile script to /builds/slave/test-pgo/build/venv/bin 01:19:04 INFO - Running setup.py install for mozrunner 01:19:04 INFO - Installing mozrunner script to /builds/slave/test-pgo/build/venv/bin 01:19:04 INFO - Running setup.py install for mozscreenshot 01:19:04 INFO - Running setup.py install for moztest 01:19:04 INFO - Running setup.py install for mozversion 01:19:04 INFO - Installing mozversion script to /builds/slave/test-pgo/build/venv/bin 01:19:04 INFO - Successfully installed manifestparser mozcrash mozdebug mozdevice mozfile mozhttpd mozinfo mozInstall mozleak mozlog moznetwork mozprocess mozprofile mozrunner mozscreenshot moztest mozversion 01:19:04 INFO - Cleaning up... 01:19:04 INFO - Return code: 0 01:19:04 INFO - Installing None into virtualenv /builds/slave/test-pgo/build/venv 01:19:04 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:19:04 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 01:19:04 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:19:04 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 01:19:04 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 01:19:04 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:19:04 INFO - retry: Calling run_command with args: [['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test-pgo/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test-pgo/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 0x7f6bc51ddb90>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1a267b0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1aeb4a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x187dbf0>, '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 0x1b7b4f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b7b9a0>, 'level': 'critical'}], 'cwd': '/builds/slave/test-pgo/build/tests/config', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test-pgo', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 01:19:04 INFO - Running command: ['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test-pgo/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test-pgo/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-pgo/build/tests/config 01:19:04 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/pip install --download-cache /builds/slave/test-pgo/build/venv/cache --timeout 120 -r /builds/slave/test-pgo/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:19:04 INFO - Using env: {'DISPLAY': ':0', 01:19:04 INFO - 'HOME': '/home/cltbld', 01:19:04 INFO - 'LANG': 'en_US.UTF-8', 01:19:04 INFO - 'LANGUAGE': 'en_US:en', 01:19:04 INFO - 'LOGNAME': 'cltbld', 01:19:04 INFO - 'MAIL': '/var/mail/cltbld', 01:19:04 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 01:19:04 INFO - 'MOZ_NO_REMOTE': '1', 01:19:04 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 01:19:04 INFO - 'NO_EM_RESTART': '1', 01:19:04 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 01:19:04 INFO - 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json', 01:19:04 INFO - 'PWD': '/builds/slave/test-pgo', 01:19:04 INFO - 'SHELL': '/bin/bash', 01:19:04 INFO - 'SHLVL': '1', 01:19:04 INFO - 'TERM': 'linux', 01:19:04 INFO - 'TMOUT': '86400', 01:19:04 INFO - 'USER': 'cltbld', 01:19:04 INFO - 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661', 01:19:04 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 01:19:04 INFO - '_': '/tools/buildbot/bin/python'} 01:19:05 INFO - Ignoring indexes: https://pypi.python.org/simple/ 01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/manifestparser 01:19:05 INFO - Running setup.py (path:/tmp/pip-KPM7uk-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/manifestparser 01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): manifestparser==1.1 from file:///builds/slave/test-pgo/build/tests/mozbase/manifestparser in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 1)) 01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozcrash 01:19:05 INFO - Running setup.py (path:/tmp/pip-DtjJz4-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozcrash 01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash==0.16 from file:///builds/slave/test-pgo/build/tests/mozbase/mozcrash in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 2)) 01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozdebug 01:19:05 INFO - Running setup.py (path:/tmp/pip-2KMWDP-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozdebug 01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdebug==0.1 from file:///builds/slave/test-pgo/build/tests/mozbase/mozdebug in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 3)) 01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozdevice 01:19:05 INFO - Running setup.py (path:/tmp/pip-E6SoEi-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozdevice 01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdevice==0.46 from file:///builds/slave/test-pgo/build/tests/mozbase/mozdevice in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 4)) 01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozfile 01:19:05 INFO - Running setup.py (path:/tmp/pip-_8K4qe-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozfile 01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile==1.2 from file:///builds/slave/test-pgo/build/tests/mozbase/mozfile in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 5)) 01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozhttpd 01:19:05 INFO - Running setup.py (path:/tmp/pip-FsS5qr-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozhttpd 01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd==0.7 from file:///builds/slave/test-pgo/build/tests/mozbase/mozhttpd in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 6)) 01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozinfo 01:19:05 INFO - Running setup.py (path:/tmp/pip-q1ziry-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozinfo 01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo==0.8 from file:///builds/slave/test-pgo/build/tests/mozbase/mozinfo in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 7)) 01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozinstall 01:19:05 INFO - Running setup.py (path:/tmp/pip-Hk5v46-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozinstall 01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozInstall==1.12 from file:///builds/slave/test-pgo/build/tests/mozbase/mozinstall in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 8)) 01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozleak 01:19:05 INFO - Running setup.py (path:/tmp/pip-04iOTN-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozleak 01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozleak==0.1 from file:///builds/slave/test-pgo/build/tests/mozbase/mozleak in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 9)) 01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozlog 01:19:05 INFO - Running setup.py (path:/tmp/pip-KlKbrW-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozlog 01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog==3.0 from file:///builds/slave/test-pgo/build/tests/mozbase/mozlog in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 10)) 01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/moznetwork 01:19:05 INFO - Running setup.py (path:/tmp/pip-lB34sR-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/moznetwork 01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork==0.27 from file:///builds/slave/test-pgo/build/tests/mozbase/moznetwork in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 11)) 01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozprocess 01:19:05 INFO - Running setup.py (path:/tmp/pip-xxeZov-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozprocess 01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess==0.22 from file:///builds/slave/test-pgo/build/tests/mozbase/mozprocess in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 12)) 01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozprofile 01:19:05 INFO - Running setup.py (path:/tmp/pip-kcD6y1-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozprofile 01:19:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile==0.27 from file:///builds/slave/test-pgo/build/tests/mozbase/mozprofile in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 13)) 01:19:05 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozrunner 01:19:05 INFO - Running setup.py (path:/tmp/pip-YCt3fr-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozrunner 01:19:06 INFO - Requirement already satisfied (use --upgrade to upgrade): mozrunner==6.10 from file:///builds/slave/test-pgo/build/tests/mozbase/mozrunner in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 14)) 01:19:06 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozscreenshot 01:19:06 INFO - Running setup.py (path:/tmp/pip-S5xTYJ-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozscreenshot 01:19:06 INFO - Requirement already satisfied (use --upgrade to upgrade): mozscreenshot==0.1 from file:///builds/slave/test-pgo/build/tests/mozbase/mozscreenshot in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 15)) 01:19:06 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/moztest 01:19:06 INFO - Running setup.py (path:/tmp/pip-EuToUc-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/moztest 01:19:06 INFO - Requirement already satisfied (use --upgrade to upgrade): moztest==0.7 from file:///builds/slave/test-pgo/build/tests/mozbase/moztest in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 16)) 01:19:06 INFO - Unpacking /builds/slave/test-pgo/build/tests/mozbase/mozversion 01:19:06 INFO - Running setup.py (path:/tmp/pip-pMR9Ds-build/setup.py) egg_info for package from file:///builds/slave/test-pgo/build/tests/mozbase/mozversion 01:19:06 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion==1.4 from file:///builds/slave/test-pgo/build/tests/mozbase/mozversion in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 17)) 01:19:06 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.0 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from mozcrash==0.16->-r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 2)) 01:19:06 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.0 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from mozcrash==0.16->-r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 2)) 01:19:06 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from mozdebug==0.1->-r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 3)) 01:19:06 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork>=0.24 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from mozdevice==0.46->-r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 4)) 01:19:06 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.19 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from mozdevice==0.46->-r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 4)) 01:19:06 INFO - Downloading/unpacking blessings>=1.3 (from mozlog==3.0->-r /builds/slave/test-pgo/build/tests/config/mozbase_requirements.txt (line 10)) 01:19:06 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:19:06 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:19:06 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:19:06 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:19:06 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:19:06 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:19:07 INFO - Downloading blessings-1.5.1.tar.gz 01:19:07 INFO - Storing download in cache at /builds/slave/test-pgo/build/venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fblessings-1.5.1.tar.gz 01:19:07 INFO - Running setup.py (path:/builds/slave/test-pgo/build/venv/build/blessings/setup.py) egg_info for package blessings 01:19:08 INFO - Installing collected packages: blessings 01:19:08 INFO - Running setup.py install for blessings 01:19:08 INFO - Successfully installed blessings 01:19:08 INFO - Cleaning up... 01:19:08 INFO - Return code: 0 01:19:08 INFO - Done creating virtualenv /builds/slave/test-pgo/build/venv. 01:19:08 INFO - Getting output from command: ['/builds/slave/test-pgo/build/venv/bin/pip', 'freeze'] 01:19:08 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/pip freeze 01:19:08 INFO - Reading from file tmpfile_stdout 01:19:08 INFO - Current package versions: 01:19:08 INFO - argparse == 1.2.1 01:19:08 INFO - blessings == 1.5.1 01:19:08 INFO - blobuploader == 1.2.4 01:19:08 INFO - docopt == 0.6.1 01:19:08 INFO - manifestparser == 1.1 01:19:08 INFO - mozInstall == 1.12 01:19:08 INFO - mozcrash == 0.16 01:19:08 INFO - mozdebug == 0.1 01:19:08 INFO - mozdevice == 0.46 01:19:08 INFO - mozfile == 1.2 01:19:08 INFO - mozhttpd == 0.7 01:19:08 INFO - mozinfo == 0.8 01:19:08 INFO - mozleak == 0.1 01:19:08 INFO - mozlog == 3.0 01:19:08 INFO - moznetwork == 0.27 01:19:08 INFO - mozprocess == 0.22 01:19:08 INFO - mozprofile == 0.27 01:19:08 INFO - mozrunner == 6.10 01:19:08 INFO - mozscreenshot == 0.1 01:19:08 INFO - mozsystemmonitor == 0.0 01:19:08 INFO - moztest == 0.7 01:19:08 INFO - mozversion == 1.4 01:19:08 INFO - psutil == 3.1.1 01:19:08 INFO - requests == 1.2.3 01:19:08 INFO - wsgiref == 0.1.2 01:19:08 INFO - Installing None into virtualenv /builds/slave/test-pgo/build/venv 01:19:08 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:08 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 01:19:08 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:19:08 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:08 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 01:19:08 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 01:19:08 INFO - retry: Calling run_command with args: [['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test-pgo/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test-pgo/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 0x7f6bc51ddb90>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1a267b0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1aeb4a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x187dbf0>, '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 0x1b7b4f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b7b9a0>, 'level': 'critical'}], 'cwd': '/builds/slave/test-pgo/build/tests/talos', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test-pgo', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 01:19:08 INFO - Running command: ['/builds/slave/test-pgo/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test-pgo/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test-pgo/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-pgo/build/tests/talos 01:19:08 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/pip install --download-cache /builds/slave/test-pgo/build/venv/cache --timeout 120 -r /builds/slave/test-pgo/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:19:08 INFO - Using env: {'DISPLAY': ':0', 01:19:08 INFO - 'HOME': '/home/cltbld', 01:19:08 INFO - 'LANG': 'en_US.UTF-8', 01:19:08 INFO - 'LANGUAGE': 'en_US:en', 01:19:08 INFO - 'LOGNAME': 'cltbld', 01:19:08 INFO - 'MAIL': '/var/mail/cltbld', 01:19:08 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 01:19:08 INFO - 'MOZ_NO_REMOTE': '1', 01:19:08 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 01:19:08 INFO - 'NO_EM_RESTART': '1', 01:19:08 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 01:19:08 INFO - 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json', 01:19:08 INFO - 'PWD': '/builds/slave/test-pgo', 01:19:08 INFO - 'SHELL': '/bin/bash', 01:19:08 INFO - 'SHLVL': '1', 01:19:08 INFO - 'TERM': 'linux', 01:19:08 INFO - 'TMOUT': '86400', 01:19:08 INFO - 'USER': 'cltbld', 01:19:08 INFO - 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661', 01:19:08 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 01:19:08 INFO - '_': '/tools/buildbot/bin/python'} 01:19:08 INFO - Ignoring indexes: https://pypi.python.org/simple/ 01:19:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash>=0.15 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/talos/requirements.txt (line 1)) 01:19:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.2 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/talos/requirements.txt (line 2)) 01:19:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd>=0.7 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/talos/requirements.txt (line 3)) 01:19:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo>=0.8 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/talos/requirements.txt (line 4)) 01:19:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.22 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/talos/requirements.txt (line 5)) 01:19:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion>=1.3 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/talos/requirements.txt (line 6)) 01:19:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile>=0.25 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/talos/requirements.txt (line 7)) 01:19:08 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test-pgo/build/tests/talos/requirements.txt (line 8)) 01:19:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.0 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from mozcrash>=0.15->-r /builds/slave/test-pgo/build/tests/talos/requirements.txt (line 1)) 01:19:08 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork>=0.24 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from mozhttpd>=0.7->-r /builds/slave/test-pgo/build/tests/talos/requirements.txt (line 3)) 01:19:08 INFO - Requirement already satisfied (use --upgrade to upgrade): blessings>=1.3 in /builds/slave/test-pgo/build/venv/lib/python2.7/site-packages (from mozlog>=3.0->mozcrash>=0.15->-r /builds/slave/test-pgo/build/tests/talos/requirements.txt (line 1)) 01:19:08 INFO - Cleaning up... 01:19:08 INFO - Return code: 0 01:19:08 INFO - Running post-action listener: _resource_record_post_action 01:19:08 INFO - Running post-action listener: _start_resource_monitoring 01:19:08 INFO - Starting resource monitoring. 01:19:08 INFO - ##### 01:19:08 INFO - ##### Running install step. 01:19:08 INFO - ##### 01:19:08 INFO - Running pre-action listener: _resource_record_pre_action 01:19:08 INFO - Running main action method: install 01:19:08 INFO - Getting output from command: ['/builds/slave/test-pgo/build/venv/bin/pip', 'freeze'] 01:19:08 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/pip freeze 01:19:08 INFO - Reading from file tmpfile_stdout 01:19:08 INFO - Detecting whether we're running mozinstall >=1.0... 01:19:08 INFO - Getting output from command: ['/builds/slave/test-pgo/build/venv/bin/mozinstall', '-h'] 01:19:08 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/mozinstall -h 01:19:08 INFO - Reading from file tmpfile_stdout 01:19:08 INFO - Output received: 01:19:08 INFO - Usage: mozinstall [options] installer 01:19:08 INFO - Options: 01:19:08 INFO - -h, --help show this help message and exit 01:19:08 INFO - -d DEST, --destination=DEST 01:19:08 INFO - Directory to install application into. [default: 01:19:08 INFO - "/builds/slave/test-pgo"] 01:19:08 INFO - --app=APP Application being installed. [default: firefox] 01:19:08 INFO - mkdir: /builds/slave/test-pgo/build/application 01:19:08 INFO - Getting output from command: ['/builds/slave/test-pgo/build/venv/bin/mozinstall', '/builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2', '--destination', '/builds/slave/test-pgo/build/application'] 01:19:08 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/mozinstall /builds/slave/test-pgo/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2 --destination /builds/slave/test-pgo/build/application 01:19:23 INFO - Reading from file tmpfile_stdout 01:19:23 INFO - Output received: 01:19:23 INFO - /builds/slave/test-pgo/build/application/firefox/firefox 01:19:23 INFO - Running post-action listener: _resource_record_post_action 01:19:23 INFO - ##### 01:19:23 INFO - ##### Running run-tests step. 01:19:23 INFO - ##### 01:19:23 INFO - Running pre-action listener: _resource_record_pre_action 01:19:23 INFO - Running main action method: run_tests 01:19:23 INFO - Running command: ['/builds/slave/test-pgo/build/venv/bin/python', '--version'] 01:19:23 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/python --version 01:19:23 INFO - Python 2.7.3 01:19:23 INFO - Return code: 0 01:19:23 INFO - grabbing minidump binary from tooltool 01:19:23 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:23 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-pgo/build/tests/config/tooltool-manifests/linux64/releng.manifest', '-o', '-c', '/builds/tooltool_cache'],), kwargs: {'error_list': [{'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x187dbf0>, '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 0x1b7b4f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b7b9a0>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test-pgo/build', 'privileged': False}, attempt #1 01:19:23 INFO - Running command: ['/tools/tooltool.py', '--url', 'https://api.pub.build.mozilla.org/tooltool/', '--authentication-file', '/builds/relengapi.tok', 'fetch', '-m', '/builds/slave/test-pgo/build/tests/config/tooltool-manifests/linux64/releng.manifest', '-o', '-c', '/builds/tooltool_cache'] in /builds/slave/test-pgo/build 01:19:23 INFO - Copy/paste: /tools/tooltool.py --url https://api.pub.build.mozilla.org/tooltool/ --authentication-file /builds/relengapi.tok fetch -m /builds/slave/test-pgo/build/tests/config/tooltool-manifests/linux64/releng.manifest -o -c /builds/tooltool_cache 01:19:23 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache 01:19:23 INFO - Return code: 0 01:19:23 INFO - Chmoding /builds/slave/test-pgo/build/linux64-minidump_stackwalk to 0755 01:19:23 INFO - mkdir: /builds/slave/test-pgo/build/blobber_upload_dir 01:19:23 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test-pgo/build/blobber_upload_dir 01:19:23 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test-pgo/build/linux64-minidump_stackwalk 01:19:23 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test-pgo/build/blobber_upload_dir 01:19:23 INFO - Running command: ['/builds/slave/test-pgo/build/venv/bin/python', '/builds/slave/test-pgo/build/tests/talos/talos/run_tests.py', '--debug', '--branchName', 'Mozilla-Aurora', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.crashreporter-symbols.zip', '--activeTests', 'a11yr:ts_paint:tpaint:sessionrestore:sessionrestore_no_auto_restore', '--executablePath', '/builds/slave/test-pgo/build/application/firefox/firefox', '--title', 'talos-linux64-ix-041', '--webServer', 'localhost'] in /builds/slave/test-pgo/build 01:19:23 INFO - Copy/paste: /builds/slave/test-pgo/build/venv/bin/python /builds/slave/test-pgo/build/tests/talos/talos/run_tests.py --debug --branchName Mozilla-Aurora --symbolsPath https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.crashreporter-symbols.zip --activeTests a11yr:ts_paint:tpaint:sessionrestore:sessionrestore_no_auto_restore --executablePath /builds/slave/test-pgo/build/application/firefox/firefox --title talos-linux64-ix-041 --webServer localhost 01:19:23 INFO - Using env: {'DISPLAY': ':0', 01:19:23 INFO - 'HOME': '/home/cltbld', 01:19:23 INFO - 'LANG': 'en_US.UTF-8', 01:19:23 INFO - 'LANGUAGE': 'en_US:en', 01:19:23 INFO - 'LOGNAME': 'cltbld', 01:19:23 INFO - 'MAIL': '/var/mail/cltbld', 01:19:23 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test-pgo/build/blobber_upload_dir', 01:19:23 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test-pgo/build/linux64-minidump_stackwalk', 01:19:23 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 01:19:23 INFO - 'MOZ_NO_REMOTE': '1', 01:19:23 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test-pgo/build/blobber_upload_dir', 01:19:23 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 01:19:23 INFO - 'NO_EM_RESTART': '1', 01:19:23 INFO - 'PATH': '/builds/slave/test-pgo/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 01:19:23 INFO - 'PROPERTIES_FILE': '/builds/slave/test-pgo/buildprops.json', 01:19:23 INFO - 'PWD': '/builds/slave/test-pgo', 01:19:23 INFO - 'PYTHONPATH': '/builds/slave/test-pgo/build/tests/talos', 01:19:23 INFO - 'SHELL': '/bin/bash', 01:19:23 INFO - 'SHLVL': '1', 01:19:23 INFO - 'TERM': 'linux', 01:19:23 INFO - 'TMOUT': '86400', 01:19:23 INFO - 'USER': 'cltbld', 01:19:23 INFO - 'XDG_SESSION_COOKIE': '7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661', 01:19:23 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 01:19:23 INFO - '_': '/tools/buildbot/bin/python'} 01:19:23 INFO - Calling ['/builds/slave/test-pgo/build/venv/bin/python', '/builds/slave/test-pgo/build/tests/talos/talos/run_tests.py', '--debug', '--branchName', 'Mozilla-Aurora', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.crashreporter-symbols.zip', '--activeTests', 'a11yr:ts_paint:tpaint:sessionrestore:sessionrestore_no_auto_restore', '--executablePath', '/builds/slave/test-pgo/build/application/firefox/firefox', '--title', 'talos-linux64-ix-041', '--webServer', 'localhost'] with output_timeout 3600 01:19:23 INFO - mozversion INFO | application_buildid: 20151029014646 01:19:23 INFO - mozversion INFO | application_changeset: 41fdefd640f368bccdeafe6446d42c0a5ad22797 01:19:23 INFO - mozversion INFO | application_display_name: FirefoxDeveloperEdition 01:19:23 INFO - mozversion INFO | application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384} 01:19:23 INFO - mozversion INFO | application_name: Firefox 01:19:23 INFO - mozversion INFO | application_remotingname: firefox-dev 01:19:23 INFO - mozversion INFO | application_repository: https://hg.mozilla.org/releases/mozilla-aurora 01:19:23 INFO - mozversion INFO | application_vendor: Mozilla 01:19:23 INFO - mozversion INFO | application_version: 43.0a2 01:19:23 INFO - mozversion INFO | platform_buildid: 20151029014646 01:19:23 INFO - mozversion INFO | platform_changeset: 41fdefd640f368bccdeafe6446d42c0a5ad22797 01:19:23 INFO - mozversion INFO | platform_repository: https://hg.mozilla.org/releases/mozilla-aurora 01:19:23 INFO - mozversion INFO | platform_version: 43.0a2 01:19:23 INFO - 2015-10-30 01:19:23,886 DEBUG : using testdate: 1446193163 01:19:23 INFO - 2015-10-30 01:19:23,886 DEBUG : actual date: 1446193163 01:19:23 INFO - 2015-10-30 01:19:23,894 INFO : Starting test suite talos-linux64-ix-041 01:19:23 INFO - 2015-10-30 01:19:23,894 INFO : Starting test a11yr 01:19:23 INFO - 2015-10-30 01:19:23,894 DEBUG : operating with platform_type : linux_ 01:19:23 INFO - 2015-10-30 01:19:23,895 INFO : Initialising browser for a11yr test... 01:19:23 INFO - 2015-10-30 01:19:23,977 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpfuDupe/profile http://localhost/getInfo.html 01:19:29 INFO - 2015-10-30 01:19:29,586 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 01:19:29 INFO - 2015-10-30 01:19:29,586 DEBUG : BROWSER_OUTPUT: colorDepth:24 01:19:29 INFO - 2015-10-30 01:19:29,586 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697 01:19:29 INFO - 2015-10-30 01:19:29,586 DEBUG : BROWSER_OUTPUT: __metrics 01:19:29 INFO - 2015-10-30 01:19:29,824 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:31 INFO - 2015-10-30 01:19:31,346 INFO : Browser initialized. 01:19:31 INFO - 2015-10-30 01:19:31,347 INFO : Running cycle 1/1 for a11yr test... 01:19:31 INFO - 2015-10-30 01:19:31,347 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpfuDupe/profile -tp file:/builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/a11y.manifest -tpchrome -tpmozafterpaint -tpnoisy -tpcycles 1 -tppagecycles 25 01:19:43 INFO - 2015-10-30 01:19:43,027 DEBUG : BROWSER_OUTPUT: RSS: Main: 131743744 01:19:43 INFO - 2015-10-30 01:19:43,027 DEBUG : BROWSER_OUTPUT: 01:19:43 INFO - 2015-10-30 01:19:43,928 DEBUG : BROWSER_OUTPUT: 01:19:43 INFO - 2015-10-30 01:19:43,928 DEBUG : BROWSER_OUTPUT: (firefox:3404): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed 01:19:43 INFO - 2015-10-30 01:19:43,936 DEBUG : BROWSER_OUTPUT: Cycle 1(1): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:19:44 INFO - 2015-10-30 01:19:44,526 DEBUG : BROWSER_OUTPUT: RSS: Main: 168964096 01:19:44 INFO - 2015-10-30 01:19:44,526 DEBUG : BROWSER_OUTPUT: 01:19:45 INFO - 2015-10-30 01:19:45,513 DEBUG : BROWSER_OUTPUT: Cycle 1(2): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:19:46 INFO - 2015-10-30 01:19:46,154 DEBUG : BROWSER_OUTPUT: RSS: Main: 173899776 01:19:46 INFO - 2015-10-30 01:19:46,154 DEBUG : BROWSER_OUTPUT: 01:19:47 INFO - 2015-10-30 01:19:47,061 DEBUG : BROWSER_OUTPUT: Cycle 1(3): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:19:47 INFO - 2015-10-30 01:19:47,702 DEBUG : BROWSER_OUTPUT: RSS: Main: 173867008 01:19:47 INFO - 2015-10-30 01:19:47,702 DEBUG : BROWSER_OUTPUT: 01:19:48 INFO - 2015-10-30 01:19:48,684 DEBUG : BROWSER_OUTPUT: Cycle 1(4): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:19:49 INFO - 2015-10-30 01:19:49,327 DEBUG : BROWSER_OUTPUT: RSS: Main: 175525888 01:19:49 INFO - 2015-10-30 01:19:49,327 DEBUG : BROWSER_OUTPUT: 01:19:50 INFO - 2015-10-30 01:19:50,313 DEBUG : BROWSER_OUTPUT: Cycle 1(5): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:19:50 INFO - 2015-10-30 01:19:50,956 DEBUG : BROWSER_OUTPUT: RSS: Main: 176009216 01:19:50 INFO - 2015-10-30 01:19:50,957 DEBUG : BROWSER_OUTPUT: 01:19:51 INFO - 2015-10-30 01:19:51,951 DEBUG : BROWSER_OUTPUT: Cycle 1(6): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:19:52 INFO - 2015-10-30 01:19:52,598 DEBUG : BROWSER_OUTPUT: RSS: Main: 176951296 01:19:52 INFO - 2015-10-30 01:19:52,598 DEBUG : BROWSER_OUTPUT: 01:19:53 INFO - 2015-10-30 01:19:53,601 DEBUG : BROWSER_OUTPUT: Cycle 1(7): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:19:54 INFO - 2015-10-30 01:19:54,244 DEBUG : BROWSER_OUTPUT: RSS: Main: 176791552 01:19:54 INFO - 2015-10-30 01:19:54,244 DEBUG : BROWSER_OUTPUT: 01:19:55 INFO - 2015-10-30 01:19:55,247 DEBUG : BROWSER_OUTPUT: Cycle 1(8): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:19:55 INFO - 2015-10-30 01:19:55,889 DEBUG : BROWSER_OUTPUT: RSS: Main: 177963008 01:19:55 INFO - 2015-10-30 01:19:55,890 DEBUG : BROWSER_OUTPUT: 01:19:56 INFO - 2015-10-30 01:19:56,791 DEBUG : BROWSER_OUTPUT: Cycle 1(9): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:19:57 INFO - 2015-10-30 01:19:57,434 DEBUG : BROWSER_OUTPUT: RSS: Main: 176898048 01:19:57 INFO - 2015-10-30 01:19:57,434 DEBUG : BROWSER_OUTPUT: 01:19:58 INFO - 2015-10-30 01:19:58,409 DEBUG : BROWSER_OUTPUT: Cycle 1(10): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:19:59 INFO - 2015-10-30 01:19:59,051 DEBUG : BROWSER_OUTPUT: RSS: Main: 177389568 01:19:59 INFO - 2015-10-30 01:19:59,051 DEBUG : BROWSER_OUTPUT: 01:20:00 INFO - 2015-10-30 01:20:00,033 DEBUG : BROWSER_OUTPUT: Cycle 1(11): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:00 INFO - 2015-10-30 01:20:00,676 DEBUG : BROWSER_OUTPUT: RSS: Main: 177696768 01:20:00 INFO - 2015-10-30 01:20:00,676 DEBUG : BROWSER_OUTPUT: 01:20:01 INFO - 2015-10-30 01:20:01,683 DEBUG : BROWSER_OUTPUT: Cycle 1(12): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:02 INFO - 2015-10-30 01:20:02,330 DEBUG : BROWSER_OUTPUT: RSS: Main: 177278976 01:20:02 INFO - 2015-10-30 01:20:02,330 DEBUG : BROWSER_OUTPUT: 01:20:03 INFO - 2015-10-30 01:20:03,365 DEBUG : BROWSER_OUTPUT: Cycle 1(13): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:04 INFO - 2015-10-30 01:20:04,015 DEBUG : BROWSER_OUTPUT: RSS: Main: 177569792 01:20:04 INFO - 2015-10-30 01:20:04,015 DEBUG : BROWSER_OUTPUT: 01:20:04 INFO - 2015-10-30 01:20:04,998 DEBUG : BROWSER_OUTPUT: Cycle 1(14): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:05 INFO - 2015-10-30 01:20:05,645 DEBUG : BROWSER_OUTPUT: RSS: Main: 176697344 01:20:05 INFO - 2015-10-30 01:20:05,645 DEBUG : BROWSER_OUTPUT: 01:20:06 INFO - 2015-10-30 01:20:06,652 DEBUG : BROWSER_OUTPUT: Cycle 1(15): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:07 INFO - 2015-10-30 01:20:07,298 DEBUG : BROWSER_OUTPUT: RSS: Main: 177803264 01:20:07 INFO - 2015-10-30 01:20:07,299 DEBUG : BROWSER_OUTPUT: 01:20:08 INFO - 2015-10-30 01:20:08,232 DEBUG : BROWSER_OUTPUT: Cycle 1(16): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:08 INFO - 2015-10-30 01:20:08,309 DEBUG : BROWSER_OUTPUT: 01:20:08 INFO - 2015-10-30 01:20:08,309 DEBUG : BROWSER_OUTPUT: (firefox:3404): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed 01:20:08 INFO - 2015-10-30 01:20:08,889 DEBUG : BROWSER_OUTPUT: RSS: Main: 176570368 01:20:08 INFO - 2015-10-30 01:20:08,889 DEBUG : BROWSER_OUTPUT: 01:20:09 INFO - 2015-10-30 01:20:09,897 DEBUG : BROWSER_OUTPUT: Cycle 1(17): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:10 INFO - 2015-10-30 01:20:10,539 DEBUG : BROWSER_OUTPUT: RSS: Main: 177291264 01:20:10 INFO - 2015-10-30 01:20:10,540 DEBUG : BROWSER_OUTPUT: 01:20:11 INFO - 2015-10-30 01:20:11,587 DEBUG : BROWSER_OUTPUT: Cycle 1(18): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:12 INFO - 2015-10-30 01:20:12,229 DEBUG : BROWSER_OUTPUT: RSS: Main: 177049600 01:20:12 INFO - 2015-10-30 01:20:12,229 DEBUG : BROWSER_OUTPUT: 01:20:13 INFO - 2015-10-30 01:20:13,219 DEBUG : BROWSER_OUTPUT: Cycle 1(19): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:13 INFO - 2015-10-30 01:20:13,861 DEBUG : BROWSER_OUTPUT: RSS: Main: 177078272 01:20:13 INFO - 2015-10-30 01:20:13,861 DEBUG : BROWSER_OUTPUT: 01:20:14 INFO - 2015-10-30 01:20:14,935 DEBUG : BROWSER_OUTPUT: Cycle 1(20): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:15 INFO - 2015-10-30 01:20:15,582 DEBUG : BROWSER_OUTPUT: RSS: Main: 176742400 01:20:15 INFO - 2015-10-30 01:20:15,582 DEBUG : BROWSER_OUTPUT: 01:20:16 INFO - 2015-10-30 01:20:16,597 DEBUG : BROWSER_OUTPUT: Cycle 1(21): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:17 INFO - 2015-10-30 01:20:17,239 DEBUG : BROWSER_OUTPUT: RSS: Main: 176521216 01:20:17 INFO - 2015-10-30 01:20:17,239 DEBUG : BROWSER_OUTPUT: 01:20:18 INFO - 2015-10-30 01:20:18,202 DEBUG : BROWSER_OUTPUT: Cycle 1(22): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:18 INFO - 2015-10-30 01:20:18,845 DEBUG : BROWSER_OUTPUT: RSS: Main: 177053696 01:20:18 INFO - 2015-10-30 01:20:18,845 DEBUG : BROWSER_OUTPUT: 01:20:19 INFO - 2015-10-30 01:20:19,827 DEBUG : BROWSER_OUTPUT: Cycle 1(23): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:20 INFO - 2015-10-30 01:20:20,474 DEBUG : BROWSER_OUTPUT: RSS: Main: 176033792 01:20:20 INFO - 2015-10-30 01:20:20,475 DEBUG : BROWSER_OUTPUT: 01:20:21 INFO - 2015-10-30 01:20:21,542 DEBUG : BROWSER_OUTPUT: Cycle 1(24): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:22 INFO - 2015-10-30 01:20:22,189 DEBUG : BROWSER_OUTPUT: RSS: Main: 177061888 01:20:22 INFO - 2015-10-30 01:20:22,189 DEBUG : BROWSER_OUTPUT: 01:20:23 INFO - 2015-10-30 01:20:23,196 DEBUG : BROWSER_OUTPUT: Cycle 1(25): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html) 01:20:23 INFO - 2015-10-30 01:20:23,839 DEBUG : BROWSER_OUTPUT: RSS: Main: 177307648 01:20:23 INFO - 2015-10-30 01:20:23,839 DEBUG : BROWSER_OUTPUT: 01:20:24 INFO - 2015-10-30 01:20:24,419 DEBUG : BROWSER_OUTPUT: 01:20:24 INFO - 2015-10-30 01:20:24,419 DEBUG : BROWSER_OUTPUT: (firefox:3404): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed 01:20:24 INFO - 2015-10-30 01:20:24,440 DEBUG : BROWSER_OUTPUT: Cycle 1(1): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:25 INFO - 2015-10-30 01:20:25,003 DEBUG : BROWSER_OUTPUT: RSS: Main: 173649920 01:20:25 INFO - 2015-10-30 01:20:25,003 DEBUG : BROWSER_OUTPUT: 01:20:25 INFO - 2015-10-30 01:20:25,584 DEBUG : BROWSER_OUTPUT: Cycle 1(2): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:26 INFO - 2015-10-30 01:20:26,147 DEBUG : BROWSER_OUTPUT: RSS: Main: 176496640 01:20:26 INFO - 2015-10-30 01:20:26,147 DEBUG : BROWSER_OUTPUT: 01:20:26 INFO - 2015-10-30 01:20:26,727 DEBUG : BROWSER_OUTPUT: Cycle 1(3): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:27 INFO - 2015-10-30 01:20:27,311 DEBUG : BROWSER_OUTPUT: RSS: Main: 177479680 01:20:27 INFO - 2015-10-30 01:20:27,311 DEBUG : BROWSER_OUTPUT: 01:20:27 INFO - 2015-10-30 01:20:27,891 DEBUG : BROWSER_OUTPUT: Cycle 1(4): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:28 INFO - 2015-10-30 01:20:28,465 DEBUG : BROWSER_OUTPUT: RSS: Main: 177627136 01:20:28 INFO - 2015-10-30 01:20:28,465 DEBUG : BROWSER_OUTPUT: 01:20:29 INFO - 2015-10-30 01:20:29,045 DEBUG : BROWSER_OUTPUT: Cycle 1(5): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:29 INFO - 2015-10-30 01:20:29,620 DEBUG : BROWSER_OUTPUT: RSS: Main: 178401280 01:20:29 INFO - 2015-10-30 01:20:29,621 DEBUG : BROWSER_OUTPUT: 01:20:30 INFO - 2015-10-30 01:20:30,192 DEBUG : BROWSER_OUTPUT: Cycle 1(6): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:30 INFO - 2015-10-30 01:20:30,765 DEBUG : BROWSER_OUTPUT: RSS: Main: 177889280 01:20:30 INFO - 2015-10-30 01:20:30,766 DEBUG : BROWSER_OUTPUT: 01:20:31 INFO - 2015-10-30 01:20:31,338 DEBUG : BROWSER_OUTPUT: Cycle 1(7): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:31 INFO - 2015-10-30 01:20:31,919 DEBUG : BROWSER_OUTPUT: RSS: Main: 180801536 01:20:31 INFO - 2015-10-30 01:20:31,919 DEBUG : BROWSER_OUTPUT: 01:20:32 INFO - 2015-10-30 01:20:32,484 DEBUG : BROWSER_OUTPUT: Cycle 1(8): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:33 INFO - 2015-10-30 01:20:33,065 DEBUG : BROWSER_OUTPUT: RSS: Main: 183078912 01:20:33 INFO - 2015-10-30 01:20:33,065 DEBUG : BROWSER_OUTPUT: 01:20:33 INFO - 2015-10-30 01:20:33,651 DEBUG : BROWSER_OUTPUT: Cycle 1(9): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:34 INFO - 2015-10-30 01:20:34,244 DEBUG : BROWSER_OUTPUT: RSS: Main: 185729024 01:20:34 INFO - 2015-10-30 01:20:34,244 DEBUG : BROWSER_OUTPUT: 01:20:34 INFO - 2015-10-30 01:20:34,824 DEBUG : BROWSER_OUTPUT: Cycle 1(10): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:35 INFO - 2015-10-30 01:20:35,414 DEBUG : BROWSER_OUTPUT: RSS: Main: 185729024 01:20:35 INFO - 2015-10-30 01:20:35,414 DEBUG : BROWSER_OUTPUT: 01:20:35 INFO - 2015-10-30 01:20:35,994 DEBUG : BROWSER_OUTPUT: Cycle 1(11): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:36 INFO - 2015-10-30 01:20:36,580 DEBUG : BROWSER_OUTPUT: RSS: Main: 184266752 01:20:36 INFO - 2015-10-30 01:20:36,580 DEBUG : BROWSER_OUTPUT: 01:20:37 INFO - 2015-10-30 01:20:37,160 DEBUG : BROWSER_OUTPUT: Cycle 1(12): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:37 INFO - 2015-10-30 01:20:37,742 DEBUG : BROWSER_OUTPUT: RSS: Main: 184328192 01:20:37 INFO - 2015-10-30 01:20:37,743 DEBUG : BROWSER_OUTPUT: 01:20:38 INFO - 2015-10-30 01:20:38,327 DEBUG : BROWSER_OUTPUT: Cycle 1(13): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:38 INFO - 2015-10-30 01:20:38,914 DEBUG : BROWSER_OUTPUT: RSS: Main: 183427072 01:20:38 INFO - 2015-10-30 01:20:38,914 DEBUG : BROWSER_OUTPUT: 01:20:39 INFO - 2015-10-30 01:20:39,493 DEBUG : BROWSER_OUTPUT: Cycle 1(14): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:40 INFO - 2015-10-30 01:20:40,075 DEBUG : BROWSER_OUTPUT: RSS: Main: 183734272 01:20:40 INFO - 2015-10-30 01:20:40,076 DEBUG : BROWSER_OUTPUT: 01:20:40 INFO - 2015-10-30 01:20:40,619 DEBUG : BROWSER_OUTPUT: Cycle 1(15): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:41 INFO - 2015-10-30 01:20:41,201 DEBUG : BROWSER_OUTPUT: RSS: Main: 183521280 01:20:41 INFO - 2015-10-30 01:20:41,202 DEBUG : BROWSER_OUTPUT: 01:20:41 INFO - 2015-10-30 01:20:41,781 DEBUG : BROWSER_OUTPUT: Cycle 1(16): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:42 INFO - 2015-10-30 01:20:42,356 DEBUG : BROWSER_OUTPUT: RSS: Main: 183009280 01:20:42 INFO - 2015-10-30 01:20:42,356 DEBUG : BROWSER_OUTPUT: 01:20:42 INFO - 2015-10-30 01:20:42,904 DEBUG : BROWSER_OUTPUT: Cycle 1(17): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:43 INFO - 2015-10-30 01:20:43,485 DEBUG : BROWSER_OUTPUT: RSS: Main: 181112832 01:20:43 INFO - 2015-10-30 01:20:43,485 DEBUG : BROWSER_OUTPUT: 01:20:44 INFO - 2015-10-30 01:20:44,065 DEBUG : BROWSER_OUTPUT: Cycle 1(18): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:44 INFO - 2015-10-30 01:20:44,647 DEBUG : BROWSER_OUTPUT: RSS: Main: 175050752 01:20:44 INFO - 2015-10-30 01:20:44,647 DEBUG : BROWSER_OUTPUT: 01:20:45 INFO - 2015-10-30 01:20:45,219 DEBUG : BROWSER_OUTPUT: Cycle 1(19): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:45 INFO - 2015-10-30 01:20:45,806 DEBUG : BROWSER_OUTPUT: RSS: Main: 177278976 01:20:45 INFO - 2015-10-30 01:20:45,806 DEBUG : BROWSER_OUTPUT: 01:20:46 INFO - 2015-10-30 01:20:46,390 DEBUG : BROWSER_OUTPUT: Cycle 1(20): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:46 INFO - 2015-10-30 01:20:46,973 DEBUG : BROWSER_OUTPUT: RSS: Main: 174940160 01:20:46 INFO - 2015-10-30 01:20:46,973 DEBUG : BROWSER_OUTPUT: 01:20:47 INFO - 2015-10-30 01:20:47,545 DEBUG : BROWSER_OUTPUT: Cycle 1(21): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:48 INFO - 2015-10-30 01:20:48,132 DEBUG : BROWSER_OUTPUT: RSS: Main: 175742976 01:20:48 INFO - 2015-10-30 01:20:48,132 DEBUG : BROWSER_OUTPUT: 01:20:48 INFO - 2015-10-30 01:20:48,712 DEBUG : BROWSER_OUTPUT: Cycle 1(22): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:49 INFO - 2015-10-30 01:20:49,286 DEBUG : BROWSER_OUTPUT: RSS: Main: 176418816 01:20:49 INFO - 2015-10-30 01:20:49,287 DEBUG : BROWSER_OUTPUT: 01:20:49 INFO - 2015-10-30 01:20:49,866 DEBUG : BROWSER_OUTPUT: Cycle 1(23): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:50 INFO - 2015-10-30 01:20:50,448 DEBUG : BROWSER_OUTPUT: RSS: Main: 176521216 01:20:50 INFO - 2015-10-30 01:20:50,448 DEBUG : BROWSER_OUTPUT: 01:20:50 INFO - 2015-10-30 01:20:50,993 DEBUG : BROWSER_OUTPUT: Cycle 1(24): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:51 INFO - 2015-10-30 01:20:51,575 DEBUG : BROWSER_OUTPUT: RSS: Main: 175362048 01:20:51 INFO - 2015-10-30 01:20:51,575 DEBUG : BROWSER_OUTPUT: 01:20:52 INFO - 2015-10-30 01:20:52,155 DEBUG : BROWSER_OUTPUT: Cycle 1(25): loaded file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/tablemutation.html (next: file:///builds/slave/test-pgo/build/tests/talos/talos/page_load_test/a11y/dhtml.html) 01:20:52 INFO - 2015-10-30 01:20:52,405 DEBUG : BROWSER_OUTPUT: RSS: Main: 182370304 01:20:52 INFO - 2015-10-30 01:20:52,405 DEBUG : BROWSER_OUTPUT: 01:20:52 INFO - 2015-10-30 01:20:52,405 DEBUG : BROWSER_OUTPUT: __start_tp_report 01:20:52 INFO - 2015-10-30 01:20:52,405 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load 01:20:52 INFO - 2015-10-30 01:20:52,405 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load_details 01:20:52 INFO - 2015-10-30 01:20:52,405 DEBUG : BROWSER_OUTPUT: |i|pagename|runs| 01:20:52 INFO - 2015-10-30 01:20:52,406 DEBUG : BROWSER_OUTPUT: |0;dhtml.html;864;909;852;918;914;921;923;923;855;924;921;926;958;931;923;861;938;992;928;1000;929;922;921;993;923 01:20:52 INFO - 2015-10-30 01:20:52,406 DEBUG : BROWSER_OUTPUT: |1;tablemutation.html;203;196;197;196;195;194;195;195;203;199;197;196;198;196;195;198;197;196;196;196;198;197;197;196;196 01:20:52 INFO - 2015-10-30 01:20:52,406 DEBUG : BROWSER_OUTPUT: __end_tp_report 01:20:52 INFO - 2015-10-30 01:20:52,406 DEBUG : BROWSER_OUTPUT: __start_cc_report 01:20:52 INFO - 2015-10-30 01:20:52,406 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_cycle_collect,5361 01:20:52 INFO - 2015-10-30 01:20:52,406 DEBUG : BROWSER_OUTPUT: __end_cc_report 01:20:52 INFO - 2015-10-30 01:20:52,406 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193252404__endTimestamp 01:20:52 INFO - 2015-10-30 01:20:52,407 DEBUG : BROWSER_OUTPUT: 01:20:52 INFO - 2015-10-30 01:20:52,407 DEBUG : BROWSER_OUTPUT: ------- Summary: start ------- 01:20:52 INFO - 2015-10-30 01:20:52,408 DEBUG : BROWSER_OUTPUT: Number of tests: 2 01:20:52 INFO - 2015-10-30 01:20:52,408 DEBUG : BROWSER_OUTPUT: 01:20:52 INFO - 2015-10-30 01:20:52,408 DEBUG : BROWSER_OUTPUT: [#0] dhtml.html Cycles:25 Average:922.76 Median:923.00 stddev:37.90 (4.1%) stddev-sans-first:36.64 01:20:52 INFO - 2015-10-30 01:20:52,409 DEBUG : BROWSER_OUTPUT: Values: 864.0 909.0 852.0 918.0 914.0 921.0 923.0 923.0 855.0 924.0 921.0 926.0 958.0 931.0 923.0 861.0 938.0 992.0 928.0 1000.0 929.0 922.0 921.0 993.0 923.0 01:20:52 INFO - 2015-10-30 01:20:52,409 DEBUG : BROWSER_OUTPUT: 01:20:52 INFO - 2015-10-30 01:20:52,409 DEBUG : BROWSER_OUTPUT: [#1] tablemutation.html Cycles:25 Average:196.88 Median:196.00 stddev:2.17 (1.1%) stddev-sans-first:1.79 01:20:52 INFO - 2015-10-30 01:20:52,409 DEBUG : BROWSER_OUTPUT: Values: 203.0 196.0 197.0 196.0 195.0 194.0 195.0 195.0 203.0 199.0 197.0 196.0 198.0 196.0 195.0 198.0 197.0 196.0 196.0 196.0 198.0 197.0 197.0 196.0 196.0 01:20:52 INFO - 2015-10-30 01:20:52,409 DEBUG : BROWSER_OUTPUT: -------- Summary: end -------- 01:20:52 INFO - 2015-10-30 01:20:52,409 DEBUG : BROWSER_OUTPUT: 01:20:52 INFO - 2015-10-30 01:20:52,969 INFO : Browser exited with error code: 0 01:20:52 INFO - 2015-10-30 01:20:52,985 INFO : Completed test a11yr (00:01:29) 01:20:52 INFO - 2015-10-30 01:20:52,985 INFO : Starting test ts_paint 01:20:52 INFO - 2015-10-30 01:20:52,985 DEBUG : operating with platform_type : linux_ 01:20:52 INFO - 2015-10-30 01:20:52,985 INFO : Initialising browser for ts_paint test... 01:20:52 INFO - 2015-10-30 01:20:52,991 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/getInfo.html 01:20:56 INFO - 2015-10-30 01:20:56,611 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 01:20:56 INFO - 2015-10-30 01:20:56,611 DEBUG : BROWSER_OUTPUT: colorDepth:24 01:20:56 INFO - 2015-10-30 01:20:56,611 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697 01:20:56 INFO - 2015-10-30 01:20:56,611 DEBUG : BROWSER_OUTPUT: __metrics 01:20:56 INFO - 2015-10-30 01:20:56,789 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,996 INFO : Browser initialized. 01:20:57 INFO - 2015-10-30 01:20:57,996 INFO : Running cycle 1/20 for ts_paint test... 01:20:57 INFO - 2015-10-30 01:20:57,996 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html 01:20:59 INFO - 2015-10-30 01:20:59,409 DEBUG : BROWSER_OUTPUT: __start_report1408__end_report 01:20:59 INFO - 2015-10-30 01:20:59,409 DEBUG : BROWSER_OUTPUT: 01:20:59 INFO - 2015-10-30 01:20:59,417 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193259413__endTimestamp 01:21:00 INFO - 2015-10-30 01:21:00,284 INFO : Browser exited with error code: 0 01:21:00 INFO - 2015-10-30 01:21:00,286 INFO : Running cycle 2/20 for ts_paint test... 01:21:00 INFO - 2015-10-30 01:21:00,286 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html 01:21:01 INFO - 2015-10-30 01:21:01,197 DEBUG : BROWSER_OUTPUT: __start_report907__end_report 01:21:01 INFO - 2015-10-30 01:21:01,197 DEBUG : BROWSER_OUTPUT: 01:21:01 INFO - 2015-10-30 01:21:01,204 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193261202__endTimestamp 01:21:01 INFO - 2015-10-30 01:21:01,873 INFO : Browser exited with error code: 0 01:21:01 INFO - 2015-10-30 01:21:01,875 INFO : Running cycle 3/20 for ts_paint test... 01:21:01 INFO - 2015-10-30 01:21:01,875 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html 01:21:02 INFO - 2015-10-30 01:21:02,808 DEBUG : BROWSER_OUTPUT: __start_report929__end_report 01:21:02 INFO - 2015-10-30 01:21:02,808 DEBUG : BROWSER_OUTPUT: 01:21:02 INFO - 2015-10-30 01:21:02,815 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193262814__endTimestamp 01:21:03 INFO - 2015-10-30 01:21:03,693 INFO : Browser exited with error code: 0 01:21:03 INFO - 2015-10-30 01:21:03,695 INFO : Running cycle 4/20 for ts_paint test... 01:21:03 INFO - 2015-10-30 01:21:03,695 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html 01:21:04 INFO - 2015-10-30 01:21:04,607 DEBUG : BROWSER_OUTPUT: __start_report906__end_report 01:21:04 INFO - 2015-10-30 01:21:04,607 DEBUG : BROWSER_OUTPUT: 01:21:04 INFO - 2015-10-30 01:21:04,615 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193264611__endTimestamp 01:21:05 INFO - 2015-10-30 01:21:05,497 INFO : Browser exited with error code: 0 01:21:05 INFO - 2015-10-30 01:21:05,499 INFO : Running cycle 5/20 for ts_paint test... 01:21:05 INFO - 2015-10-30 01:21:05,499 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html 01:21:06 INFO - 2015-10-30 01:21:06,419 DEBUG : BROWSER_OUTPUT: __start_report924__end_report 01:21:06 INFO - 2015-10-30 01:21:06,420 DEBUG : BROWSER_OUTPUT: 01:21:06 INFO - 2015-10-30 01:21:06,427 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193266426__endTimestamp 01:21:07 INFO - 2015-10-30 01:21:07,285 INFO : Browser exited with error code: 0 01:21:07 INFO - 2015-10-30 01:21:07,287 INFO : Running cycle 6/20 for ts_paint test... 01:21:07 INFO - 2015-10-30 01:21:07,287 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html 01:21:08 INFO - 2015-10-30 01:21:08,236 DEBUG : BROWSER_OUTPUT: __start_report948__end_report 01:21:08 INFO - 2015-10-30 01:21:08,236 DEBUG : BROWSER_OUTPUT: 01:21:08 INFO - 2015-10-30 01:21:08,252 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193268246__endTimestamp 01:21:09 INFO - 2015-10-30 01:21:09,137 INFO : Browser exited with error code: 0 01:21:09 INFO - 2015-10-30 01:21:09,139 INFO : Running cycle 7/20 for ts_paint test... 01:21:09 INFO - 2015-10-30 01:21:09,139 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html 01:21:10 INFO - 2015-10-30 01:21:10,032 DEBUG : BROWSER_OUTPUT: __start_report900__end_report 01:21:10 INFO - 2015-10-30 01:21:10,032 DEBUG : BROWSER_OUTPUT: 01:21:10 INFO - 2015-10-30 01:21:10,040 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193270040__endTimestamp 01:21:10 INFO - 2015-10-30 01:21:10,777 INFO : Browser exited with error code: 0 01:21:10 INFO - 2015-10-30 01:21:10,778 INFO : Running cycle 8/20 for ts_paint test... 01:21:10 INFO - 2015-10-30 01:21:10,778 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html 01:21:11 INFO - 2015-10-30 01:21:11,677 DEBUG : BROWSER_OUTPUT: __start_report901__end_report 01:21:11 INFO - 2015-10-30 01:21:11,678 DEBUG : BROWSER_OUTPUT: 01:21:11 INFO - 2015-10-30 01:21:11,685 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193271684__endTimestamp 01:21:12 INFO - 2015-10-30 01:21:12,466 INFO : Browser exited with error code: 0 01:21:12 INFO - 2015-10-30 01:21:12,467 INFO : Running cycle 9/20 for ts_paint test... 01:21:12 INFO - 2015-10-30 01:21:12,467 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html 01:21:13 INFO - 2015-10-30 01:21:13,356 DEBUG : BROWSER_OUTPUT: __start_report888__end_report 01:21:13 INFO - 2015-10-30 01:21:13,356 DEBUG : BROWSER_OUTPUT: 01:21:13 INFO - 2015-10-30 01:21:13,363 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193273363__endTimestamp 01:21:14 INFO - 2015-10-30 01:21:14,104 INFO : Browser exited with error code: 0 01:21:14 INFO - 2015-10-30 01:21:14,106 INFO : Running cycle 10/20 for ts_paint test... 01:21:14 INFO - 2015-10-30 01:21:14,106 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html 01:21:15 INFO - 2015-10-30 01:21:15,062 DEBUG : BROWSER_OUTPUT: __start_report959__end_report 01:21:15 INFO - 2015-10-30 01:21:15,062 DEBUG : BROWSER_OUTPUT: 01:21:15 INFO - 2015-10-30 01:21:15,070 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193275068__endTimestamp 01:21:15 INFO - 2015-10-30 01:21:15,929 INFO : Browser exited with error code: 0 01:21:15 INFO - 2015-10-30 01:21:15,931 INFO : Running cycle 11/20 for ts_paint test... 01:21:15 INFO - 2015-10-30 01:21:15,931 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html 01:21:16 INFO - 2015-10-30 01:21:16,885 DEBUG : BROWSER_OUTPUT: __start_report945__end_report 01:21:16 INFO - 2015-10-30 01:21:16,885 DEBUG : BROWSER_OUTPUT: 01:21:16 INFO - 2015-10-30 01:21:16,901 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193276900__endTimestamp 01:21:17 INFO - 2015-10-30 01:21:17,773 INFO : Browser exited with error code: 0 01:21:17 INFO - 2015-10-30 01:21:17,775 INFO : Running cycle 12/20 for ts_paint test... 01:21:17 INFO - 2015-10-30 01:21:17,775 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html 01:21:18 INFO - 2015-10-30 01:21:18,675 DEBUG : BROWSER_OUTPUT: __start_report900__end_report 01:21:18 INFO - 2015-10-30 01:21:18,675 DEBUG : BROWSER_OUTPUT: 01:21:18 INFO - 2015-10-30 01:21:18,691 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193278689__endTimestamp 01:21:19 INFO - 2015-10-30 01:21:19,462 INFO : Browser exited with error code: 0 01:21:19 INFO - 2015-10-30 01:21:19,463 INFO : Running cycle 13/20 for ts_paint test... 01:21:19 INFO - 2015-10-30 01:21:19,463 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html 01:21:20 INFO - 2015-10-30 01:21:20,411 DEBUG : BROWSER_OUTPUT: __start_report944__end_report 01:21:20 INFO - 2015-10-30 01:21:20,411 DEBUG : BROWSER_OUTPUT: 01:21:20 INFO - 2015-10-30 01:21:20,419 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193280416__endTimestamp 01:21:21 INFO - 2015-10-30 01:21:21,229 INFO : Browser exited with error code: 0 01:21:21 INFO - 2015-10-30 01:21:21,231 INFO : Running cycle 14/20 for ts_paint test... 01:21:21 INFO - 2015-10-30 01:21:21,231 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html 01:21:22 INFO - 2015-10-30 01:21:22,163 DEBUG : BROWSER_OUTPUT: __start_report924__end_report 01:21:22 INFO - 2015-10-30 01:21:22,163 DEBUG : BROWSER_OUTPUT: 01:21:22 INFO - 2015-10-30 01:21:22,183 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193282179__endTimestamp 01:21:23 INFO - 2015-10-30 01:21:23,121 INFO : Browser exited with error code: 0 01:21:23 INFO - 2015-10-30 01:21:23,123 INFO : Running cycle 15/20 for ts_paint test... 01:21:23 INFO - 2015-10-30 01:21:23,123 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html 01:21:24 INFO - 2015-10-30 01:21:24,111 DEBUG : BROWSER_OUTPUT: __start_report980__end_report 01:21:24 INFO - 2015-10-30 01:21:24,111 DEBUG : BROWSER_OUTPUT: 01:21:24 INFO - 2015-10-30 01:21:24,114 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193284114__endTimestamp 01:21:24 INFO - 2015-10-30 01:21:24,911 INFO : Browser exited with error code: 0 01:21:24 INFO - 2015-10-30 01:21:24,912 INFO : Running cycle 16/20 for ts_paint test... 01:21:24 INFO - 2015-10-30 01:21:24,913 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html 01:21:25 INFO - 2015-10-30 01:21:25,833 DEBUG : BROWSER_OUTPUT: __start_report914__end_report 01:21:25 INFO - 2015-10-30 01:21:25,833 DEBUG : BROWSER_OUTPUT: 01:21:25 INFO - 2015-10-30 01:21:25,849 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193285841__endTimestamp 01:21:26 INFO - 2015-10-30 01:21:26,600 INFO : Browser exited with error code: 0 01:21:26 INFO - 2015-10-30 01:21:26,601 INFO : Running cycle 17/20 for ts_paint test... 01:21:26 INFO - 2015-10-30 01:21:26,601 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html 01:21:27 INFO - 2015-10-30 01:21:27,553 DEBUG : BROWSER_OUTPUT: __start_report947__end_report 01:21:27 INFO - 2015-10-30 01:21:27,553 DEBUG : BROWSER_OUTPUT: 01:21:27 INFO - 2015-10-30 01:21:27,561 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193287558__endTimestamp 01:21:28 INFO - 2015-10-30 01:21:28,489 INFO : Browser exited with error code: 0 01:21:28 INFO - 2015-10-30 01:21:28,491 INFO : Running cycle 18/20 for ts_paint test... 01:21:28 INFO - 2015-10-30 01:21:28,491 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html 01:21:29 INFO - 2015-10-30 01:21:29,411 DEBUG : BROWSER_OUTPUT: __start_report914__end_report 01:21:29 INFO - 2015-10-30 01:21:29,411 DEBUG : BROWSER_OUTPUT: 01:21:29 INFO - 2015-10-30 01:21:29,427 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193289425__endTimestamp 01:21:30 INFO - 2015-10-30 01:21:30,385 INFO : Browser exited with error code: 0 01:21:30 INFO - 2015-10-30 01:21:30,387 INFO : Running cycle 19/20 for ts_paint test... 01:21:30 INFO - 2015-10-30 01:21:30,387 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html 01:21:31 INFO - 2015-10-30 01:21:31,319 DEBUG : BROWSER_OUTPUT: __start_report932__end_report 01:21:31 INFO - 2015-10-30 01:21:31,319 DEBUG : BROWSER_OUTPUT: 01:21:31 INFO - 2015-10-30 01:21:31,335 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193291328__endTimestamp 01:21:32 INFO - 2015-10-30 01:21:32,209 INFO : Browser exited with error code: 0 01:21:32 INFO - 2015-10-30 01:21:32,211 INFO : Running cycle 20/20 for ts_paint test... 01:21:32 INFO - 2015-10-30 01:21:32,211 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpxYCuYC/profile http://localhost/startup_test/tspaint_test.html 01:21:33 INFO - 2015-10-30 01:21:33,142 DEBUG : BROWSER_OUTPUT: __start_report924__end_report 01:21:33 INFO - 2015-10-30 01:21:33,143 DEBUG : BROWSER_OUTPUT: 01:21:33 INFO - 2015-10-30 01:21:33,150 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193293149__endTimestamp 01:21:34 INFO - 2015-10-30 01:21:34,113 INFO : Browser exited with error code: 0 01:21:34 INFO - 2015-10-30 01:21:34,132 INFO : Completed test ts_paint (00:00:41) 01:21:34 INFO - 2015-10-30 01:21:34,132 INFO : Starting test tpaint 01:21:34 INFO - 2015-10-30 01:21:34,132 DEBUG : operating with platform_type : linux_ 01:21:34 INFO - 2015-10-30 01:21:34,132 INFO : Initialising browser for tpaint test... 01:21:34 INFO - 2015-10-30 01:21:34,139 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpyxWdBu/profile http://localhost/getInfo.html 01:21:37 INFO - 2015-10-30 01:21:37,676 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 01:21:37 INFO - 2015-10-30 01:21:37,677 DEBUG : BROWSER_OUTPUT: colorDepth:24 01:21:37 INFO - 2015-10-30 01:21:37,677 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697 01:21:37 INFO - 2015-10-30 01:21:37,677 DEBUG : BROWSER_OUTPUT: __metrics 01:21:37 INFO - 2015-10-30 01:21:37,894 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:39 INFO - 2015-10-30 01:21:39,207 INFO : Browser initialized. 01:21:39 INFO - 2015-10-30 01:21:39,207 INFO : Running cycle 1/1 for tpaint test... 01:21:39 INFO - 2015-10-30 01:21:39,208 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpyxWdBu/profile file:///builds/slave/test-pgo/build/tests/talos/talos/startup_test/tpaint.html?auto=1 01:22:04 INFO - 2015-10-30 01:22:04,159 DEBUG : BROWSER_OUTPUT: __start_report154.4649999999997|154.54499999999985|155.5650000000005|155.71999999999753|156.51000000000113|159.875|161.10999999999876|161.95000000000073|167.01999999999998|172.6800000000003|173.51499999999942|174.47000000000116|175.65499999999884|176.26999999999862|179.33500000000095|183.79499999999825|187.35499999999956|190.1449999999968|204.45000000000073|249.59000000000015__end_report__startTimestamp1446193324156__endTimestamp 01:22:04 INFO - 2015-10-30 01:22:04,159 DEBUG : BROWSER_OUTPUT: openingTimes=154.54499999999985,155.5650000000005,155.71999999999753,156.51000000000113,159.875,161.10999999999876,161.95000000000073,167.01999999999998,172.6800000000003,173.51499999999942,174.47000000000116,175.65499999999884,176.26999999999862,179.33500000000095,183.79499999999825,187.35499999999956,190.1449999999968,204.45000000000073,249.59000000000015 01:22:04 INFO - 2015-10-30 01:22:04,159 DEBUG : BROWSER_OUTPUT: avgOpenTime:174.70 01:22:04 INFO - 2015-10-30 01:22:04,159 DEBUG : BROWSER_OUTPUT: minOpenTime:154.46 01:22:04 INFO - 2015-10-30 01:22:04,159 DEBUG : BROWSER_OUTPUT: maxOpenTime:249.59 01:22:04 INFO - 2015-10-30 01:22:04,159 DEBUG : BROWSER_OUTPUT: medOpenTime:173.09749999999985 01:22:04 INFO - 2015-10-30 01:22:04,159 DEBUG : BROWSER_OUTPUT: __xulWinOpenTime:173.09749999999985 01:22:04 INFO - 2015-10-30 01:22:04,978 INFO : Browser exited with error code: 0 01:22:04 INFO - 2015-10-30 01:22:04,994 INFO : Completed test tpaint (00:00:30) 01:22:04 INFO - 2015-10-30 01:22:04,994 INFO : Starting test sessionrestore 01:22:04 INFO - 2015-10-30 01:22:04,994 DEBUG : operating with platform_type : linux_ 01:22:04 INFO - 2015-10-30 01:22:04,994 INFO : Initialising browser for sessionrestore test... 01:22:05 INFO - 2015-10-30 01:22:05,001 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpMnKcoU/profile http://localhost/getInfo.html 01:22:08 INFO - 2015-10-30 01:22:08,846 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 01:22:08 INFO - 2015-10-30 01:22:08,846 DEBUG : BROWSER_OUTPUT: colorDepth:24 01:22:08 INFO - 2015-10-30 01:22:08,846 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1151/811 01:22:08 INFO - 2015-10-30 01:22:08,846 DEBUG : BROWSER_OUTPUT: __metrics 01:22:09 INFO - 2015-10-30 01:22:09,011 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:10 INFO - 2015-10-30 01:22:10,369 INFO : Browser initialized. 01:22:10 INFO - 2015-10-30 01:22:10,370 INFO : Running cycle 1/10 for sessionrestore test... 01:22:10 INFO - 2015-10-30 01:22:10,370 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpMnKcoU/profile/sessionstore.js 01:22:10 INFO - 2015-10-30 01:22:10,372 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpMnKcoU/profile http://localhost/startup_test/sessionrestore/index.html 01:22:13 INFO - 2015-10-30 01:22:13,952 DEBUG : BROWSER_OUTPUT: __start_report1734__end_report 01:22:13 INFO - 2015-10-30 01:22:13,952 DEBUG : BROWSER_OUTPUT: 01:22:13 INFO - 2015-10-30 01:22:13,952 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193333951__endTimestamp 01:22:13 INFO - 2015-10-30 01:22:13,952 DEBUG : BROWSER_OUTPUT: 01:22:15 INFO - 2015-10-30 01:22:15,409 INFO : Browser exited with error code: 0 01:22:15 INFO - 2015-10-30 01:22:15,411 INFO : Running cycle 2/10 for sessionrestore test... 01:22:15 INFO - 2015-10-30 01:22:15,411 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpMnKcoU/profile/sessionstore.js 01:22:15 INFO - 2015-10-30 01:22:15,413 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpMnKcoU/profile http://localhost/startup_test/sessionrestore/index.html 01:22:17 INFO - 2015-10-30 01:22:17,940 DEBUG : BROWSER_OUTPUT: __start_report1465__end_report 01:22:17 INFO - 2015-10-30 01:22:17,940 DEBUG : BROWSER_OUTPUT: 01:22:17 INFO - 2015-10-30 01:22:17,940 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193337938__endTimestamp 01:22:17 INFO - 2015-10-30 01:22:17,940 DEBUG : BROWSER_OUTPUT: 01:22:19 INFO - 2015-10-30 01:22:19,625 INFO : Browser exited with error code: 0 01:22:19 INFO - 2015-10-30 01:22:19,627 INFO : Running cycle 3/10 for sessionrestore test... 01:22:19 INFO - 2015-10-30 01:22:19,627 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpMnKcoU/profile/sessionstore.js 01:22:19 INFO - 2015-10-30 01:22:19,629 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpMnKcoU/profile http://localhost/startup_test/sessionrestore/index.html 01:22:22 INFO - 2015-10-30 01:22:22,158 DEBUG : BROWSER_OUTPUT: __start_report1446__end_report 01:22:22 INFO - 2015-10-30 01:22:22,159 DEBUG : BROWSER_OUTPUT: 01:22:22 INFO - 2015-10-30 01:22:22,159 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193342155__endTimestamp 01:22:22 INFO - 2015-10-30 01:22:22,159 DEBUG : BROWSER_OUTPUT: 01:22:23 INFO - 2015-10-30 01:22:23,837 INFO : Browser exited with error code: 0 01:22:23 INFO - 2015-10-30 01:22:23,839 INFO : Running cycle 4/10 for sessionrestore test... 01:22:23 INFO - 2015-10-30 01:22:23,839 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpMnKcoU/profile/sessionstore.js 01:22:23 INFO - 2015-10-30 01:22:23,841 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpMnKcoU/profile http://localhost/startup_test/sessionrestore/index.html 01:22:26 INFO - 2015-10-30 01:22:26,448 DEBUG : BROWSER_OUTPUT: __start_report1491__end_report 01:22:26 INFO - 2015-10-30 01:22:26,449 DEBUG : BROWSER_OUTPUT: 01:22:26 INFO - 2015-10-30 01:22:26,449 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193346445__endTimestamp 01:22:26 INFO - 2015-10-30 01:22:26,449 DEBUG : BROWSER_OUTPUT: 01:22:28 INFO - 2015-10-30 01:22:28,125 INFO : Browser exited with error code: 0 01:22:28 INFO - 2015-10-30 01:22:28,127 INFO : Running cycle 5/10 for sessionrestore test... 01:22:28 INFO - 2015-10-30 01:22:28,127 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpMnKcoU/profile/sessionstore.js 01:22:28 INFO - 2015-10-30 01:22:28,129 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpMnKcoU/profile http://localhost/startup_test/sessionrestore/index.html 01:22:30 INFO - 2015-10-30 01:22:30,662 DEBUG : BROWSER_OUTPUT: __start_report1469__end_report 01:22:30 INFO - 2015-10-30 01:22:30,663 DEBUG : BROWSER_OUTPUT: 01:22:30 INFO - 2015-10-30 01:22:30,663 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193350660__endTimestamp 01:22:30 INFO - 2015-10-30 01:22:30,663 DEBUG : BROWSER_OUTPUT: 01:22:32 INFO - 2015-10-30 01:22:32,369 INFO : Browser exited with error code: 0 01:22:32 INFO - 2015-10-30 01:22:32,371 INFO : Running cycle 6/10 for sessionrestore test... 01:22:32 INFO - 2015-10-30 01:22:32,371 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpMnKcoU/profile/sessionstore.js 01:22:32 INFO - 2015-10-30 01:22:32,373 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpMnKcoU/profile http://localhost/startup_test/sessionrestore/index.html 01:22:34 INFO - 2015-10-30 01:22:34,902 DEBUG : BROWSER_OUTPUT: __start_report1469__end_report 01:22:34 INFO - 2015-10-30 01:22:34,902 DEBUG : BROWSER_OUTPUT: 01:22:34 INFO - 2015-10-30 01:22:34,902 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193354901__endTimestamp 01:22:34 INFO - 2015-10-30 01:22:34,902 DEBUG : BROWSER_OUTPUT: 01:22:36 INFO - 2015-10-30 01:22:36,657 INFO : Browser exited with error code: 0 01:22:36 INFO - 2015-10-30 01:22:36,659 INFO : Running cycle 7/10 for sessionrestore test... 01:22:36 INFO - 2015-10-30 01:22:36,659 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpMnKcoU/profile/sessionstore.js 01:22:36 INFO - 2015-10-30 01:22:36,661 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpMnKcoU/profile http://localhost/startup_test/sessionrestore/index.html 01:22:39 INFO - 2015-10-30 01:22:39,224 DEBUG : BROWSER_OUTPUT: __start_report1494__end_report 01:22:39 INFO - 2015-10-30 01:22:39,224 DEBUG : BROWSER_OUTPUT: 01:22:39 INFO - 2015-10-30 01:22:39,224 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193359222__endTimestamp 01:22:39 INFO - 2015-10-30 01:22:39,224 DEBUG : BROWSER_OUTPUT: 01:22:40 INFO - 2015-10-30 01:22:40,969 INFO : Browser exited with error code: 0 01:22:40 INFO - 2015-10-30 01:22:40,971 INFO : Running cycle 8/10 for sessionrestore test... 01:22:40 INFO - 2015-10-30 01:22:40,971 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpMnKcoU/profile/sessionstore.js 01:22:40 INFO - 2015-10-30 01:22:40,973 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpMnKcoU/profile http://localhost/startup_test/sessionrestore/index.html 01:22:43 INFO - 2015-10-30 01:22:43,560 DEBUG : BROWSER_OUTPUT: __start_report1490__end_report 01:22:43 INFO - 2015-10-30 01:22:43,561 DEBUG : BROWSER_OUTPUT: 01:22:43 INFO - 2015-10-30 01:22:43,561 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193363560__endTimestamp 01:22:43 INFO - 2015-10-30 01:22:43,561 DEBUG : BROWSER_OUTPUT: 01:22:45 INFO - 2015-10-30 01:22:45,238 INFO : Browser exited with error code: 0 01:22:45 INFO - 2015-10-30 01:22:45,239 INFO : Running cycle 9/10 for sessionrestore test... 01:22:45 INFO - 2015-10-30 01:22:45,240 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpMnKcoU/profile/sessionstore.js 01:22:45 INFO - 2015-10-30 01:22:45,242 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpMnKcoU/profile http://localhost/startup_test/sessionrestore/index.html 01:22:47 INFO - 2015-10-30 01:22:47,773 DEBUG : BROWSER_OUTPUT: __start_report1453__end_report 01:22:47 INFO - 2015-10-30 01:22:47,773 DEBUG : BROWSER_OUTPUT: 01:22:47 INFO - 2015-10-30 01:22:47,773 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193367771__endTimestamp 01:22:47 INFO - 2015-10-30 01:22:47,773 DEBUG : BROWSER_OUTPUT: 01:22:49 INFO - 2015-10-30 01:22:49,525 INFO : Browser exited with error code: 0 01:22:49 INFO - 2015-10-30 01:22:49,527 INFO : Running cycle 10/10 for sessionrestore test... 01:22:49 INFO - 2015-10-30 01:22:49,527 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpMnKcoU/profile/sessionstore.js 01:22:49 INFO - 2015-10-30 01:22:49,529 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmpMnKcoU/profile http://localhost/startup_test/sessionrestore/index.html 01:22:52 INFO - 2015-10-30 01:22:52,060 DEBUG : BROWSER_OUTPUT: __start_report1482__end_report 01:22:52 INFO - 2015-10-30 01:22:52,060 DEBUG : BROWSER_OUTPUT: 01:22:52 INFO - 2015-10-30 01:22:52,060 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193372059__endTimestamp 01:22:52 INFO - 2015-10-30 01:22:52,060 DEBUG : BROWSER_OUTPUT: 01:22:53 INFO - 2015-10-30 01:22:53,789 INFO : Browser exited with error code: 0 01:22:53 INFO - 2015-10-30 01:22:53,803 INFO : Completed test sessionrestore (00:00:48) 01:22:53 INFO - 2015-10-30 01:22:53,803 INFO : Starting test sessionrestore_no_auto_restore 01:22:53 INFO - 2015-10-30 01:22:53,803 DEBUG : operating with platform_type : linux_ 01:22:53 INFO - 2015-10-30 01:22:53,803 INFO : Initialising browser for sessionrestore_no_auto_restore test... 01:22:53 INFO - 2015-10-30 01:22:53,809 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmp6YRPR7/profile http://localhost/getInfo.html 01:22:57 INFO - 2015-10-30 01:22:57,527 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 01:22:57 INFO - 2015-10-30 01:22:57,527 DEBUG : BROWSER_OUTPUT: colorDepth:24 01:22:57 INFO - 2015-10-30 01:22:57,527 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1151/811 01:22:57 INFO - 2015-10-30 01:22:57,527 DEBUG : BROWSER_OUTPUT: __metrics 01:22:57 INFO - 2015-10-30 01:22:57,669 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:59 INFO - 2015-10-30 01:22:59,161 INFO : Browser initialized. 01:22:59 INFO - 2015-10-30 01:22:59,162 INFO : Running cycle 1/10 for sessionrestore_no_auto_restore test... 01:22:59 INFO - 2015-10-30 01:22:59,162 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp6YRPR7/profile/sessionstore.js 01:22:59 INFO - 2015-10-30 01:22:59,164 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmp6YRPR7/profile http://localhost/startup_test/sessionrestore/index.html 01:23:00 INFO - 2015-10-30 01:23:00,535 DEBUG : BROWSER_OUTPUT: __start_report884__end_report 01:23:00 INFO - 2015-10-30 01:23:00,536 DEBUG : BROWSER_OUTPUT: 01:23:00 INFO - 2015-10-30 01:23:00,536 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193380531__endTimestamp 01:23:00 INFO - 2015-10-30 01:23:00,536 DEBUG : BROWSER_OUTPUT: 01:23:01 INFO - 2015-10-30 01:23:01,449 INFO : Browser exited with error code: 0 01:23:01 INFO - 2015-10-30 01:23:01,451 INFO : Running cycle 2/10 for sessionrestore_no_auto_restore test... 01:23:01 INFO - 2015-10-30 01:23:01,451 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp6YRPR7/profile/sessionstore.js 01:23:01 INFO - 2015-10-30 01:23:01,453 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmp6YRPR7/profile http://localhost/startup_test/sessionrestore/index.html 01:23:02 INFO - 2015-10-30 01:23:02,462 DEBUG : BROWSER_OUTPUT: __start_report606__end_report 01:23:02 INFO - 2015-10-30 01:23:02,463 DEBUG : BROWSER_OUTPUT: 01:23:02 INFO - 2015-10-30 01:23:02,464 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193382460__endTimestamp 01:23:02 INFO - 2015-10-30 01:23:02,464 DEBUG : BROWSER_OUTPUT: 01:23:03 INFO - 2015-10-30 01:23:03,297 INFO : Browser exited with error code: 0 01:23:03 INFO - 2015-10-30 01:23:03,299 INFO : Running cycle 3/10 for sessionrestore_no_auto_restore test... 01:23:03 INFO - 2015-10-30 01:23:03,299 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp6YRPR7/profile/sessionstore.js 01:23:03 INFO - 2015-10-30 01:23:03,301 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmp6YRPR7/profile http://localhost/startup_test/sessionrestore/index.html 01:23:04 INFO - 2015-10-30 01:23:04,371 DEBUG : BROWSER_OUTPUT: __start_report662__end_report 01:23:04 INFO - 2015-10-30 01:23:04,371 DEBUG : BROWSER_OUTPUT: 01:23:04 INFO - 2015-10-30 01:23:04,371 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193384364__endTimestamp 01:23:04 INFO - 2015-10-30 01:23:04,371 DEBUG : BROWSER_OUTPUT: 01:23:05 INFO - 2015-10-30 01:23:05,333 INFO : Browser exited with error code: 0 01:23:05 INFO - 2015-10-30 01:23:05,335 INFO : Running cycle 4/10 for sessionrestore_no_auto_restore test... 01:23:05 INFO - 2015-10-30 01:23:05,335 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp6YRPR7/profile/sessionstore.js 01:23:05 INFO - 2015-10-30 01:23:05,337 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmp6YRPR7/profile http://localhost/startup_test/sessionrestore/index.html 01:23:06 INFO - 2015-10-30 01:23:06,370 DEBUG : BROWSER_OUTPUT: __start_report595__end_report 01:23:06 INFO - 2015-10-30 01:23:06,370 DEBUG : BROWSER_OUTPUT: 01:23:06 INFO - 2015-10-30 01:23:06,371 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193386368__endTimestamp 01:23:06 INFO - 2015-10-30 01:23:06,371 DEBUG : BROWSER_OUTPUT: 01:23:07 INFO - 2015-10-30 01:23:07,185 INFO : Browser exited with error code: 0 01:23:07 INFO - 2015-10-30 01:23:07,187 INFO : Running cycle 5/10 for sessionrestore_no_auto_restore test... 01:23:07 INFO - 2015-10-30 01:23:07,187 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp6YRPR7/profile/sessionstore.js 01:23:07 INFO - 2015-10-30 01:23:07,189 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmp6YRPR7/profile http://localhost/startup_test/sessionrestore/index.html 01:23:08 INFO - 2015-10-30 01:23:08,278 DEBUG : BROWSER_OUTPUT: __start_report644__end_report 01:23:08 INFO - 2015-10-30 01:23:08,278 DEBUG : BROWSER_OUTPUT: 01:23:08 INFO - 2015-10-30 01:23:08,278 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193388276__endTimestamp 01:23:08 INFO - 2015-10-30 01:23:08,278 DEBUG : BROWSER_OUTPUT: 01:23:09 INFO - 2015-10-30 01:23:09,225 INFO : Browser exited with error code: 0 01:23:09 INFO - 2015-10-30 01:23:09,227 INFO : Running cycle 6/10 for sessionrestore_no_auto_restore test... 01:23:09 INFO - 2015-10-30 01:23:09,227 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp6YRPR7/profile/sessionstore.js 01:23:09 INFO - 2015-10-30 01:23:09,229 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmp6YRPR7/profile http://localhost/startup_test/sessionrestore/index.html 01:23:10 INFO - 2015-10-30 01:23:10,241 DEBUG : BROWSER_OUTPUT: __start_report606__end_report 01:23:10 INFO - 2015-10-30 01:23:10,241 DEBUG : BROWSER_OUTPUT: 01:23:10 INFO - 2015-10-30 01:23:10,241 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193390238__endTimestamp 01:23:10 INFO - 2015-10-30 01:23:10,241 DEBUG : BROWSER_OUTPUT: 01:23:11 INFO - 2015-10-30 01:23:11,169 INFO : Browser exited with error code: 0 01:23:11 INFO - 2015-10-30 01:23:11,171 INFO : Running cycle 7/10 for sessionrestore_no_auto_restore test... 01:23:11 INFO - 2015-10-30 01:23:11,171 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp6YRPR7/profile/sessionstore.js 01:23:11 INFO - 2015-10-30 01:23:11,173 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmp6YRPR7/profile http://localhost/startup_test/sessionrestore/index.html 01:23:12 INFO - 2015-10-30 01:23:12,201 DEBUG : BROWSER_OUTPUT: __start_report614__end_report 01:23:12 INFO - 2015-10-30 01:23:12,202 DEBUG : BROWSER_OUTPUT: 01:23:12 INFO - 2015-10-30 01:23:12,202 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193392195__endTimestamp 01:23:12 INFO - 2015-10-30 01:23:12,202 DEBUG : BROWSER_OUTPUT: 01:23:13 INFO - 2015-10-30 01:23:13,169 INFO : Browser exited with error code: 0 01:23:13 INFO - 2015-10-30 01:23:13,171 INFO : Running cycle 8/10 for sessionrestore_no_auto_restore test... 01:23:13 INFO - 2015-10-30 01:23:13,171 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp6YRPR7/profile/sessionstore.js 01:23:13 INFO - 2015-10-30 01:23:13,173 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmp6YRPR7/profile http://localhost/startup_test/sessionrestore/index.html 01:23:14 INFO - 2015-10-30 01:23:14,190 DEBUG : BROWSER_OUTPUT: __start_report587__end_report 01:23:14 INFO - 2015-10-30 01:23:14,190 DEBUG : BROWSER_OUTPUT: 01:23:14 INFO - 2015-10-30 01:23:14,190 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193394188__endTimestamp 01:23:14 INFO - 2015-10-30 01:23:14,190 DEBUG : BROWSER_OUTPUT: 01:23:15 INFO - 2015-10-30 01:23:15,121 INFO : Browser exited with error code: 0 01:23:15 INFO - 2015-10-30 01:23:15,123 INFO : Running cycle 9/10 for sessionrestore_no_auto_restore test... 01:23:15 INFO - 2015-10-30 01:23:15,123 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp6YRPR7/profile/sessionstore.js 01:23:15 INFO - 2015-10-30 01:23:15,125 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmp6YRPR7/profile http://localhost/startup_test/sessionrestore/index.html 01:23:16 INFO - 2015-10-30 01:23:16,134 DEBUG : BROWSER_OUTPUT: __start_report611__end_report 01:23:16 INFO - 2015-10-30 01:23:16,134 DEBUG : BROWSER_OUTPUT: 01:23:16 INFO - 2015-10-30 01:23:16,134 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193396131__endTimestamp 01:23:16 INFO - 2015-10-30 01:23:16,134 DEBUG : BROWSER_OUTPUT: 01:23:17 INFO - 2015-10-30 01:23:17,121 INFO : Browser exited with error code: 0 01:23:17 INFO - 2015-10-30 01:23:17,123 INFO : Running cycle 10/10 for sessionrestore_no_auto_restore test... 01:23:17 INFO - 2015-10-30 01:23:17,123 DEBUG : Reinstalling /builds/slave/test-pgo/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp6YRPR7/profile/sessionstore.js 01:23:17 INFO - 2015-10-30 01:23:17,125 DEBUG : command line: /builds/slave/test-pgo/build/application/firefox/firefox -profile /tmp/tmp6YRPR7/profile http://localhost/startup_test/sessionrestore/index.html 01:23:18 INFO - 2015-10-30 01:23:18,173 DEBUG : BROWSER_OUTPUT: __start_report598__end_report 01:23:18 INFO - 2015-10-30 01:23:18,174 DEBUG : BROWSER_OUTPUT: 01:23:18 INFO - 2015-10-30 01:23:18,174 DEBUG : BROWSER_OUTPUT: __startTimestamp1446193398167__endTimestamp 01:23:18 INFO - 2015-10-30 01:23:18,174 DEBUG : BROWSER_OUTPUT: 01:23:19 INFO - 2015-10-30 01:23:19,113 INFO : Browser exited with error code: 0 01:23:19 INFO - 2015-10-30 01:23:19,131 INFO : Completed test sessionrestore_no_auto_restore (00:00:25) 01:23:19 INFO - 2015-10-30 01:23:19,131 INFO : Completed test suite (00:03:55) 01:23:19 INFO - 2015-10-30 01:23:19,131 DEBUG : Working with test: a11yr 01:23:19 INFO - 2015-10-30 01:23:19,131 DEBUG : Generating results file: a11yr 01:23:19 INFO - 2015-10-30 01:23:19,131 DEBUG : Working with test: ts_paint 01:23:19 INFO - 2015-10-30 01:23:19,131 DEBUG : Generating results file: ts_paint 01:23:19 INFO - 2015-10-30 01:23:19,131 DEBUG : Working with test: tpaint 01:23:19 INFO - 2015-10-30 01:23:19,131 DEBUG : Generating results file: tpaint 01:23:19 INFO - 2015-10-30 01:23:19,132 DEBUG : Working with test: sessionrestore 01:23:19 INFO - 2015-10-30 01:23:19,132 DEBUG : Generating results file: sessionrestore 01:23:19 INFO - 2015-10-30 01:23:19,132 DEBUG : Working with test: sessionrestore_no_auto_restore 01:23:19 INFO - 2015-10-30 01:23:19,132 DEBUG : Generating results file: sessionrestore_no_auto_restore 01:23:19 INFO - 2015-10-30 01:23:19,132 INFO : Posting result 0 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 01:23:19 INFO - 2015-10-30 01:23:19,180 DEBUG : process_Request line: a11yr_paint graph.html#tests=[[223,52,35]] 01:23:19 INFO - 2015-10-30 01:23:19,181 DEBUG : process_Request line: a11yr_paint 425.65 graph.html#tests=[[223,52,35]] 01:23:19 INFO - 2015-10-30 01:23:19,181 INFO : Posting result 1 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 01:23:19 INFO - 2015-10-30 01:23:19,256 DEBUG : process_Request line: ts_paint graph.html#tests=[[83,52,35]] 01:23:19 INFO - 2015-10-30 01:23:19,256 DEBUG : process_Request line: ts_paint 944.92 graph.html#tests=[[83,52,35]] 01:23:19 INFO - 2015-10-30 01:23:19,256 INFO : Posting result 2 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 01:23:19 INFO - 2015-10-30 01:23:19,293 DEBUG : process_Request line: tpaint graph.html#tests=[[82,52,35]] 01:23:19 INFO - 2015-10-30 01:23:19,293 DEBUG : process_Request line: tpaint 175.65 graph.html#tests=[[82,52,35]] 01:23:19 INFO - 2015-10-30 01:23:19,294 INFO : Posting result 3 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 01:23:19 INFO - 2015-10-30 01:23:19,343 DEBUG : process_Request line: sessionrestore graph.html#tests=[[313,52,35]] 01:23:19 INFO - 2015-10-30 01:23:19,343 DEBUG : process_Request line: sessionrestore 1497.35 graph.html#tests=[[313,52,35]] 01:23:19 INFO - 2015-10-30 01:23:19,343 INFO : Posting result 4 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 01:23:19 INFO - 2015-10-30 01:23:19,393 DEBUG : process_Request line: sessionrestore_no_auto_restore graph.html#tests=[[315,52,35]] 01:23:19 INFO - 2015-10-30 01:23:19,393 DEBUG : process_Request line: sessionrestore_no_auto_restore 636.10 graph.html#tests=[[315,52,35]] 01:23:19 INFO - 2015-10-30 01:23:19,395 INFO : TALOSDATA: [{"talos_counters": {}, "results": {"dhtml.html": [864.0, 909.0, 852.0, 918.0, 914.0, 921.0, 923.0, 923.0, 855.0, 924.0, 921.0, 926.0, 958.0, 931.0, 923.0, 861.0, 938.0, 992.0, 928.0, 1000.0, 929.0, 922.0, 921.0, 993.0, 923.0], "tablemutation.html": [203.0, 196.0, 197.0, 196.0, 195.0, 194.0, 195.0, 195.0, 203.0, 199.0, 197.0, 196.0, 198.0, 196.0, 195.0, 198.0, 197.0, 196.0, 196.0, 196.0, 198.0, 197.0, 197.0, 196.0, 196.0]}, "summary": {"suite": 425.64739539812047, "subtests": {"dhtml.html": {"std": 35.87127351919483, "min": 852.0, "max": 1000.0, "median": 923.0, "filtered": 923.0, "mean": 925.2083333333334}, "tablemutation.html": {"std": 1.7514874630819752, "min": 194.0, "max": 203.0, "median": 196.0, "filtered": 196.0, "mean": 196.625}}}, "test_machine": {"platform": "x86_64", "osversion": "Ubuntu 12.04", "os": "linux", "name": "talos-linux64-ix-041"}, "testrun": {"date": 1446193163, "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": [1408.0, 907.0, 929.0, 906.0, 924.0, 948.0, 900.0, 901.0, 888.0, 959.0, 945.0, 900.0, 944.0, 924.0, 980.0, 914.0, 947.0, 914.0, 932.0, 924.0]}, "summary": {"suite": 924.0, "subtests": {"ts_paint": {"std": 23.100047367173318, "min": 888.0, "max": 980.0, "median": 924.0, "filtered": 924.0, "mean": 925.578947368421}}}, "test_machine": {"platform": "x86_64", "osversion": "Ubuntu 12.04", "os": "linux", "name": "talos-linux64-ix-041"}, "testrun": {"date": 1446193163, "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": [154.4649999999997, 154.54499999999985, 155.5650000000005, 155.71999999999753, 156.51000000000113, 159.875, 161.10999999999876, 161.95000000000073, 167.01999999999998, 172.6800000000003, 173.51499999999942, 174.47000000000116, 175.65499999999884, 176.26999999999862, 179.33500000000095, 183.79499999999825, 187.35499999999956, 190.1449999999968, 204.45000000000073, 249.59000000000015]}, "summary": {"suite": 175.65499999999884, "subtests": {"tpaint": {"std": 21.614525815345182, "min": 159.875, "max": 249.59000000000015, "median": 175.65499999999884, "filtered": 175.65499999999884, "mean": 181.14766666666628}}}, "test_machine": {"platform": "x86_64", "osversion": "Ubuntu 12.04", "os": "linux", "name": "talos-linux64-ix-041"}, "testrun": {"date": 1446193163, "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": [1734.0, 1465.0, 1446.0, 1491.0, 1469.0, 1469.0, 1494.0, 1490.0, 1453.0, 1482.0]}, "summary": {"suite": 1469.0, "subtests": {"sessionrestore": {"std": 16.191752206174996, "min": 1446.0, "max": 1494.0, "median": 1469.0, "filtered": 1469.0, "mean": 1473.2222222222222}}}, "test_machine": {"platform": "x86_64", "osversion": "Ubuntu 12.04", "os": "linux", "name": "talos-linux64-ix-041"}, "testrun": {"date": 1446193163, "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": [884.0, 606.0, 662.0, 595.0, 644.0, 606.0, 614.0, 587.0, 611.0, 598.0]}, "summary": {"suite": 606.0, "subtests": {"sessionrestore_no_auto_restore": {"std": 22.818121453499778, "min": 587.0, "max": 662.0, "median": 606.0, "filtered": 606.0, "mean": 613.6666666666666}}}, "test_machine": {"platform": "x86_64", "osversion": "Ubuntu 12.04", "os": "linux", "name": "talos-linux64-ix-041"}, "testrun": {"date": 1446193163, "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:19 INFO - RETURN: a11yr_paint: 425.65 01:23:19 INFO - RETURN: ts_paint: 944.92 01:23:19 INFO - RETURN: tpaint: 175.65 01:23:19 INFO - RETURN: sessionrestore: 1497.35 01:23:19 INFO - RETURN: sessionrestore_no_auto_restore: 636.10 01:23:19 INFO - TinderboxPrint: TalosResult: {"graphserver": {"sessionrestore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[313,52,35]]", "result": "1497.35"}, "a11yr_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[223,52,35]]", "result": "425.65"}, "tpaint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[82,52,35]]", "result": "175.65"}, "ts_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[83,52,35]]", "result": "944.92"}, "sessionrestore_no_auto_restore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[315,52,35]]", "result": "636.10"}}} 01:23:19 INFO - Return code: 0 01:23:19 INFO - # TBPL SUCCESS # 01:23:19 INFO - Running post-action listener: _resource_record_post_action 01:23:19 INFO - Running post-run listener: _resource_record_post_run 01:23:20 INFO - Total resource usage - Wall time: 250s; CPU: 13.0%; Read bytes: 4665344; Write bytes: 359305216; Read time: 1764; Write time: 345632 01:23:20 INFO - install - Wall time: 14s; CPU: 13.0%; Read bytes: 0; Write bytes: 462848; Read time: 0; Write time: 52 01:23:20 INFO - run-tests - Wall time: 236s; CPU: 13.0%; Read bytes: 2904064; Write bytes: 311754752; Read time: 1344; Write time: 305568 01:23:20 INFO - Running post-run listener: _upload_blobber_files 01:23:20 INFO - Blob upload gear active. 01:23:20 INFO - There are no files to upload in the directory. Skipping the blob upload mechanism ... 01:23:20 INFO - Copying logs to upload dir... 01:23:20 INFO - mkdir: /builds/slave/test-pgo/build/upload/logs program finished with exit code 0 elapsedTime=307.807514 ========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 5 mins, 7 secs) (at 2015-10-30 01:23:20.444779) ========= ========= Started set props: build_url (results: 0, elapsed: 0 secs) (at 2015-10-30 01:23:20.448425) ========= bash -c 'for file in `ls -1`; do cat $file; done' in dir /builds/slave/test-pgo/properties (timeout 1200 secs) watching logfiles {} argv: ['bash', '-c', 'for file in `ls -1`; do cat $file; done'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PWD=/builds/slave/test-pgo/properties SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False build_url:https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2 program finished with exit code 0 elapsedTime=0.009877 build_url: 'https://queue.taskcluster.net/v1/task/eZRTgdcURW6p-nqY4yFlSQ/artifacts/public/build/firefox-43.0a2.en-US.linux-x86_64.tar.bz2' ========= Finished set props: build_url (results: 0, elapsed: 0 secs) (at 2015-10-30 01:23:20.501733) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:23:20.502124) ========= rm -f oauth.txt in dir /builds/slave/test-pgo/. (timeout 1200 secs) watching logfiles {} argv: ['rm', '-f', 'oauth.txt'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PWD=/builds/slave/test-pgo SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=7f67ac1ceef7774224e327f2000001f6-1446192266.120970-2008475661 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.004520 ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-10-30 01:23:20.551769) ========= ========= Started reboot slave lost (results: 0, elapsed: 4 secs) (at 2015-10-30 01:23:20.552092) ========= ========= Finished reboot slave lost (results: 0, elapsed: 4 secs) (at 2015-10-30 01:23:24.820086) =========