builder: mozilla-central_ubuntu64_hw_test-g4-e10s slave: talos-linux64-ix-038 starttime: 1509317119.41 results: success (0) revision: 09cdea082e9abee362b89d8ab6ca9c8b282583d8 ========= Started set props: master (results: 0, elapsed: 0 secs) (at 2017-10-29 15:45:19.413799) ========= master: http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/ ========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2017-10-29 15:45:19.414423) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-10-29 15:45:19.414730) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-10-29 15:45:19.494805) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-10-29 15:45:19.495115) ========= bash -c 'wget -Oarchiver_client.py --no-check-certificate --tries=10 --waitretry=3 https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py' in dir /builds/slave/test/. (timeout 1200 secs) watching logfiles {} argv: ['bash', '-c', 'wget -Oarchiver_client.py --no-check-certificate --tries=10 --waitretry=3 https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PWD=/builds/slave/test SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False --2017-10-29 15:45:19-- 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: 12179 (12K) [text/x-python] Saving to: `archiver_client.py' 0K .......... . 100% 51.1M=0s 2017-10-29 15:45:19 (51.1 MB/s) - `archiver_client.py' saved [12179/12179] program finished with exit code 0 elapsedTime=0.107627 ========= master_lag: 0.03 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-10-29 15:45:19.631245) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-10-29 15:45:19.631584) ========= rm -rf scripts properties in dir /builds/slave/test/. (timeout 1200 secs) watching logfiles {} argv: ['rm', '-rf', 'scripts', 'properties'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PWD=/builds/slave/test SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.017790 ========= master_lag: 0.05 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-10-29 15:45:19.699190) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 21 secs) (at 2017-10-29 15:45:19.699546) ========= bash -c 'python archiver_client.py mozharness --repo mozilla-central --rev 09cdea082e9abee362b89d8ab6ca9c8b282583d8 --destination scripts --debug' in dir /builds/slave/test/. (timeout 1200 secs) watching logfiles {} argv: ['bash', '-c', 'python archiver_client.py mozharness --repo mozilla-central --rev 09cdea082e9abee362b89d8ab6ca9c8b282583d8 --destination scripts --debug'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PWD=/builds/slave/test SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 2017-10-29 15:45:19,765 truncating revision to first 12 chars 2017-10-29 15:45:19,765 Setting DEBUG logging. 2017-10-29 15:45:19,765 attempt 1/10 2017-10-29 15:45:19,765 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/mozilla-central/09cdea082e9a?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness 2017-10-29 15:45:20,454 attempt 1/10 2017-10-29 15:45:21,175 current task status: no status available at this point. state: STARTED 2017-10-29 15:45:21,176 sleeping for 9.00s (attempt 1/10) 2017-10-29 15:45:30,185 attempt 2/10 2017-10-29 15:45:30,558 current task status: Task completed! Check 's3_urls' for upload locations. state: SUCCESS 2017-10-29 15:45:30,875 unpacking tar archive at: mozilla-central-09cdea082e9a/testing/mozharness/ program finished with exit code 0 elapsedTime=21.681836 ========= master_lag: 0.02 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 21 secs) (at 2017-10-29 15:45:41.398906) ========= ========= Started set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-10-29 15:45:41.399241) ========= script_repo_revision: 09cdea082e9abee362b89d8ab6ca9c8b282583d8 ========= Finished set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-10-29 15:45:41.399658) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-10-29 15:45:41.399921) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-10-29 15:45:41.663592) ========= ========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 11 mins, 36 secs) (at 2017-10-29 15:45:41.664262) ========= /tools/buildbot/bin/python scripts/scripts/talos_script.py --suite g4-e10s --add-option --webServer,localhost --branch-name Firefox-Non-PGO --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Firefox-Non-PGO in dir /builds/slave/test/. (timeout 3600 secs) (maxTime 7200 secs) watching logfiles {} argv: ['/tools/buildbot/bin/python', 'scripts/scripts/talos_script.py', '--suite', 'g4-e10s', '--add-option', '--webServer,localhost', '--branch-name', 'Firefox-Non-PGO', '--cfg', 'talos/linux_config.py', '--download-symbols', 'ondemand', '--use-talos-json', '--blob-upload-branch', 'Firefox-Non-PGO'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PROPERTIES_FILE=/builds/slave/test/buildprops.json PWD=/builds/slave/test SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 15:45:41 INFO - MultiFileLogger online at 20171029 15:45:41 in /builds/slave/test 15:45:41 INFO - Run as scripts/scripts/talos_script.py --suite g4-e10s --add-option --webServer,localhost --branch-name Firefox-Non-PGO --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Firefox-Non-PGO 15:45:41 INFO - Dumping config to /builds/slave/test/logs/localconfig.json. 15:45:41 INFO - {'append_to_log': False, 15:45:41 INFO - 'base_work_dir': '/builds/slave/test', 15:45:41 INFO - 'blob_upload_branch': 'Firefox-Non-PGO', 15:45:41 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt', 15:45:41 INFO - 'branch': 'Firefox-Non-PGO', 15:45:41 INFO - 'buildbot_json_path': 'buildprops.json', 15:45:41 INFO - 'code_coverage': False, 15:45:41 INFO - 'config_files': ('talos/linux_config.py',), 15:45:41 INFO - 'default_actions': ('clobber', 15:45:41 INFO - 'read-buildbot-config', 15:45:41 INFO - 'download-and-extract', 15:45:41 INFO - 'populate-webroot', 15:45:41 INFO - 'create-virtualenv', 15:45:41 INFO - 'install', 15:45:41 INFO - 'setup-mitmproxy', 15:45:41 INFO - 'run-tests'), 15:45:41 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 15:45:41 INFO - 'disable_ccov_upload': False, 15:45:41 INFO - 'disable_stylo': False, 15:45:41 INFO - 'download_minidump_stackwalk': True, 15:45:41 INFO - 'download_symbols': 'ondemand', 15:45:41 INFO - 'enable_stylo': False, 15:45:41 INFO - 'enable_webrender': False, 15:45:41 INFO - 'exes': {'tooltool.py': '/tools/tooltool.py'}, 15:45:41 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 15:45:41 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 15:45:41 INFO - 'gecko_profile': False, 15:45:41 INFO - 'gecko_profile_interval': 0, 15:45:41 INFO - 'installer_path': 'installer.exe', 15:45:41 INFO - 'log_level': 'info', 15:45:41 INFO - 'log_name': 'talos', 15:45:41 INFO - 'log_to_console': True, 15:45:41 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk', 15:45:41 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest', 15:45:41 INFO - 'opt_config_files': (), 15:45:41 INFO - 'pip_index': False, 15:45:41 INFO - 'suite': 'g4-e10s', 15:45:41 INFO - 'system_bits': '32', 15:45:41 INFO - 'talos_extra_options': ('--webServer', 'localhost'), 15:45:41 INFO - 'title': 'talos-linux64-ix-038', 15:45:41 INFO - 'tooltool_cache': '/builds/tooltool_cache', 15:45:41 INFO - 'use_talos_json': True, 15:45:41 INFO - 'verify': 'False', 15:45:41 INFO - 'virtualenv_path': '/builds/slave/test/build/venv', 15:45:41 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 15:45:41 INFO - 'work_dir': 'build'} 15:45:41 INFO - [mozharness: 2017-10-29 22:45:41.862711Z] Running clobber step. 15:45:41 INFO - Running pre-action listener: _resource_record_pre_action 15:45:41 INFO - Running main action method: clobber 15:45:41 INFO - rmtree: /builds/slave/test/build 15:45:41 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1 15:45:43 INFO - Running post-action listener: _resource_record_post_action 15:45:43 INFO - [mozharness: 2017-10-29 22:45:43.460885Z] Finished clobber step (success) 15:45:43 INFO - [mozharness: 2017-10-29 22:45:43.460981Z] Running read-buildbot-config step. 15:45:43 INFO - Running pre-action listener: _resource_record_pre_action 15:45:43 INFO - Running main action method: read_buildbot_config 15:45:43 INFO - Using buildbot properties: 15:45:43 INFO - { 15:45:43 INFO - "project": "", 15:45:43 INFO - "product": "firefox", 15:45:43 INFO - "who": "archaeopteryx@coole-files.de", 15:45:43 INFO - "installer_path": "public/build/target.tar.bz2", 15:45:43 INFO - "builddir": "mozilla-central_ubuntu64_hw_test-g4-e10s", 15:45:43 INFO - "repository": "https://hg.mozilla.org/mozilla-central", 15:45:43 INFO - "buildername": "Ubuntu HW 12.04 x64 mozilla-central talos g4-e10s", 15:45:43 INFO - "stage_platform": "linux64", 15:45:43 INFO - "basedir": "/builds/slave/test", 15:45:43 INFO - "buildnumber": 879, 15:45:43 INFO - "platform": "ubuntu64_hw", 15:45:43 INFO - "master": "http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/", 15:45:43 INFO - "slavebuilddir": "test", 15:45:43 INFO - "taskId": "PkCy2utRRJWfacoxJLS-xA", 15:45:43 INFO - "branch": "mozilla-central", 15:45:43 INFO - "script_repo_revision": "production", 15:45:43 INFO - "revision": "09cdea082e9abee362b89d8ab6ca9c8b282583d8", 15:45:43 INFO - "slavename": "talos-linux64-ix-038", 15:45:43 INFO - "repo_path": "mozilla-central" 15:45:43 INFO - } 15:45:43 INFO - Finding installer, test and symbols from parent task. 15:45:43 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/PkCy2utRRJWfacoxJLS-xA'}, attempt #1 15:45:43 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/PkCy2utRRJWfacoxJLS-xA'}, attempt #1 15:45:44 INFO - Task dependencies: QMTqhJs6Rr-6xXFHz6mTCQ 15:45:44 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/QMTqhJs6Rr-6xXFHz6mTCQ'}, attempt #1 15:45:45 INFO - Set installer_url: https://queue.taskcluster.net/v1/task/QMTqhJs6Rr-6xXFHz6mTCQ/artifacts/public/build/target.tar.bz2 15:45:45 INFO - Set test_packages_url: https://queue.taskcluster.net/v1/task/QMTqhJs6Rr-6xXFHz6mTCQ/artifacts/public/build/target.test_packages.json 15:45:45 INFO - Set symbols_url: https://queue.taskcluster.net/v1/task/QMTqhJs6Rr-6xXFHz6mTCQ/artifacts/public/build/target.crashreporter-symbols.zip 15:45:45 INFO - Running post-action listener: _resource_record_post_action 15:45:45 INFO - [mozharness: 2017-10-29 22:45:45.230588Z] Finished read-buildbot-config step (success) 15:45:45 INFO - [mozharness: 2017-10-29 22:45:45.230802Z] Running download-and-extract step. 15:45:45 INFO - Running pre-action listener: _resource_record_pre_action 15:45:45 INFO - Running main action method: download_and_extract 15:45:45 INFO - mkdir: /builds/slave/test/build/tests 15:45:45 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.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://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 15:45:45 INFO - trying https://queue.taskcluster.net/v1/task/QMTqhJs6Rr-6xXFHz6mTCQ/artifacts/public/build/target.test_packages.json 15:45:45 INFO - Downloading https://queue.taskcluster.net/v1/task/QMTqhJs6Rr-6xXFHz6mTCQ/artifacts/public/build/target.test_packages.json to /builds/slave/test/build/target.test_packages.json 15:45:45 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/QMTqhJs6Rr-6xXFHz6mTCQ/artifacts/public/build/target.test_packages.json', 'file_name': '/builds/slave/test/build/target.test_packages.json'}, attempt #1 15:45:45 INFO - Downloaded 989 bytes. 15:45:45 INFO - Reading from file /builds/slave/test/build/target.test_packages.json 15:45:45 INFO - Using the following test package requirements: 15:45:45 INFO - {u'awsy': [u'target.common.tests.zip', u'target.awsy.tests.zip'], 15:45:45 INFO - u'common': [u'target.common.tests.zip'], 15:45:45 INFO - u'cppunittest': [u'target.common.tests.zip', u'target.cppunittest.tests.zip'], 15:45:45 INFO - u'gtest': [u'target.common.tests.zip', u'target.gtest.tests.zip'], 15:45:45 INFO - u'jittest': [u'target.common.tests.zip', u'target.jsshell.zip'], 15:45:45 INFO - u'mochitest': [u'target.common.tests.zip', u'target.mochitest.tests.zip'], 15:45:45 INFO - u'mozbase': [u'target.common.tests.zip'], 15:45:45 INFO - u'reftest': [u'target.common.tests.zip', u'target.reftest.tests.zip'], 15:45:45 INFO - u'talos': [u'target.common.tests.zip', u'target.talos.tests.zip'], 15:45:45 INFO - u'web-platform': [u'target.common.tests.zip', 15:45:45 INFO - u'target.web-platform.tests.tar.gz'], 15:45:45 INFO - u'xpcshell': [u'target.common.tests.zip', u'target.xpcshell.tests.zip']} 15:45:45 INFO - Downloading packages: [u'target.common.tests.zip', u'target.talos.tests.zip'] for test suite categories: ['common', 'talos'] 15:45:45 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/QMTqhJs6Rr-6xXFHz6mTCQ/artifacts/public/build/target.common.tests.zip 15:45:45 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/QMTqhJs6Rr-6xXFHz6mTCQ/artifacts/public/build/target.common.tests.zip'}, attempt #1 15:45:45 INFO - Fetch https://queue.taskcluster.net/v1/task/QMTqhJs6Rr-6xXFHz6mTCQ/artifacts/public/build/target.common.tests.zip into memory 15:45:59 INFO - Content-Length response header: 56330041 15:45:59 INFO - Bytes received: 56330041 15:46:10 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/QMTqhJs6Rr-6xXFHz6mTCQ/artifacts/public/build/target.talos.tests.zip 15:46:10 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/QMTqhJs6Rr-6xXFHz6mTCQ/artifacts/public/build/target.talos.tests.zip'}, attempt #1 15:46:10 INFO - Fetch https://queue.taskcluster.net/v1/task/QMTqhJs6Rr-6xXFHz6mTCQ/artifacts/public/build/target.talos.tests.zip into memory 15:46:15 INFO - Content-Length response header: 18770379 15:46:15 INFO - Bytes received: 18770379 15:46:15 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.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://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 15:46:15 INFO - trying https://queue.taskcluster.net/v1/task/QMTqhJs6Rr-6xXFHz6mTCQ/artifacts/public/build/target.tar.bz2 15:46:15 INFO - Downloading https://queue.taskcluster.net/v1/task/QMTqhJs6Rr-6xXFHz6mTCQ/artifacts/public/build/target.tar.bz2 to /builds/slave/test/build/target.tar.bz2 15:46:15 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/QMTqhJs6Rr-6xXFHz6mTCQ/artifacts/public/build/target.tar.bz2', 'file_name': '/builds/slave/test/build/target.tar.bz2'}, attempt #1 15:46:27 INFO - Downloaded 62944725 bytes. 15:46:27 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/QMTqhJs6Rr-6xXFHz6mTCQ/artifacts/public/build/target.tar.bz2 15:46:27 INFO - mkdir: /builds/slave/test/properties 15:46:27 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url 15:46:27 INFO - Writing to file /builds/slave/test/properties/build_url 15:46:27 INFO - Contents: 15:46:27 INFO - build_url:https://queue.taskcluster.net/v1/task/QMTqhJs6Rr-6xXFHz6mTCQ/artifacts/public/build/target.tar.bz2 15:46:27 INFO - Running post-action listener: _resource_record_post_action 15:46:27 INFO - Running post-action listener: find_tests_for_verification 15:46:27 INFO - Running post-action listener: set_extra_try_arguments 15:46:27 INFO - [mozharness: 2017-10-29 22:46:27.901577Z] Finished download-and-extract step (success) 15:46:27 INFO - [mozharness: 2017-10-29 22:46:27.901840Z] Running populate-webroot step. 15:46:27 INFO - Running pre-action listener: _resource_record_pre_action 15:46:27 INFO - Running main action method: populate_webroot 15:46:27 INFO - {'suites': {'chromez-e10s': {'tests': ['tresize', 'tcanvasmark']}, 15:46:27 INFO - 'chromez-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 15:46:27 INFO - 'tests': ['tresize', 15:46:27 INFO - 'tcanvasmark']}, 15:46:27 INFO - 'dromaeojs-e10s': {'tests': ['dromaeo_css', 'kraken']}, 15:46:27 INFO - 'dromaeojs-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 15:46:27 INFO - 'tests': ['dromaeo_css', 15:46:27 INFO - 'kraken']}, 15:46:27 INFO - 'g1-e10s': {'pagesets_name': 'tp5n.zip', 15:46:27 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 15:46:27 INFO - 'g1-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 15:46:27 INFO - 'talos_options': ['--disable-stylo'], 15:46:27 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 15:46:27 INFO - 'g2-e10s': {'pagesets_name': 'tp5n.zip', 15:46:27 INFO - 'tests': ['damp', 'tps']}, 15:46:27 INFO - 'g2-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 15:46:27 INFO - 'talos_options': ['--disable-stylo'], 15:46:27 INFO - 'tests': ['damp', 'tps']}, 15:46:27 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']}, 15:46:27 INFO - 'g3-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 15:46:27 INFO - 'tests': ['dromaeo_dom']}, 15:46:27 INFO - 'g4-e10s': {'tests': ['basic_compositor_video', 'glvideo']}, 15:46:27 INFO - 'g4-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 15:46:27 INFO - 'tests': ['basic_compositor_video', 15:46:27 INFO - 'glvideo']}, 15:46:27 INFO - 'g5-e10s': {'pagesets_name': 'tp5n.zip', 15:46:27 INFO - 'tests': ['ts_paint_webext', 'tp5o_webext']}, 15:46:27 INFO - 'g5-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 15:46:27 INFO - 'talos_options': ['--disable-stylo'], 15:46:27 INFO - 'tests': ['ts_paint_webext', 15:46:27 INFO - 'tp5o_webext']}, 15:46:27 INFO - 'h1-e10s': {'tests': ['ts_paint_heavy']}, 15:46:27 INFO - 'h2-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 15:46:27 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 15:46:27 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 15:46:27 INFO - 'talos_options': ['--mitmproxy', 15:46:27 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 15:46:27 INFO - '--firstNonBlankPaint'], 15:46:27 INFO - 'tests': ['tp6_google_heavy', 15:46:27 INFO - 'tp6_youtube_heavy', 15:46:27 INFO - 'tp6_amazon_heavy', 15:46:27 INFO - 'tp6_facebook_heavy']}, 15:46:27 INFO - 'other-e10s': {'tests': ['a11yr', 15:46:27 INFO - 'ts_paint', 15:46:27 INFO - 'tpaint', 15:46:27 INFO - 'sessionrestore', 15:46:27 INFO - 'sessionrestore_many_windows', 15:46:27 INFO - 'sessionrestore_no_auto_restore', 15:46:27 INFO - 'tabpaint', 15:46:27 INFO - 'cpstartup']}, 15:46:27 INFO - 'other-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 15:46:27 INFO - 'tests': ['a11yr', 15:46:27 INFO - 'ts_paint', 15:46:27 INFO - 'tpaint', 15:46:27 INFO - 'sessionrestore', 15:46:27 INFO - 'sessionrestore_many_windows', 15:46:27 INFO - 'sessionrestore_no_auto_restore', 15:46:27 INFO - 'tabpaint', 15:46:27 INFO - 'cpstartup']}, 15:46:27 INFO - 'perf-reftest-e10s': {'tests': ['perf_reftest']}, 15:46:27 INFO - 'perf-reftest-singletons-e10s': {'tests': ['perf_reftest_singletons']}, 15:46:27 INFO - 'perf-reftest-singletons-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 15:46:27 INFO - 'tests': ['perf_reftest_singletons']}, 15:46:27 INFO - 'perf-reftest-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 15:46:27 INFO - 'tests': ['perf_reftest']}, 15:46:27 INFO - 'speedometer-e10s': {'tests': ['speedometer']}, 15:46:27 INFO - 'speedometer-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 15:46:27 INFO - 'tests': ['speedometer']}, 15:46:27 INFO - 'svgr-e10s': {'tests': ['tsvgx', 15:46:27 INFO - 'tsvgr_opacity', 15:46:27 INFO - 'tart', 15:46:27 INFO - 'tscrollx', 15:46:27 INFO - 'tsvg_static']}, 15:46:27 INFO - 'svgr-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 15:46:27 INFO - 'tests': ['tsvgx', 15:46:27 INFO - 'tsvgr_opacity', 15:46:27 INFO - 'tart', 15:46:27 INFO - 'tscrollx', 15:46:27 INFO - 'tsvg_static']}, 15:46:27 INFO - 'tp5o-e10s': {'pagesets_name': 'tp5n.zip', 'tests': ['tp5o']}, 15:46:27 INFO - 'tp5o-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 15:46:27 INFO - 'talos_options': ['--disable-stylo'], 15:46:27 INFO - 'tests': ['tp5o']}, 15:46:27 INFO - 'tp6-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 15:46:27 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 15:46:27 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 15:46:27 INFO - 'talos_options': ['--mitmproxy', 15:46:27 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 15:46:27 INFO - '--firstNonBlankPaint'], 15:46:27 INFO - 'tests': ['tp6_google', 15:46:27 INFO - 'tp6_youtube', 15:46:27 INFO - 'tp6_amazon', 15:46:27 INFO - 'tp6_facebook']}, 15:46:27 INFO - 'tp6-stylo-disabled-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 15:46:27 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 15:46:27 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 15:46:27 INFO - 'talos_options': ['--disable-stylo', 15:46:27 INFO - '--mitmproxy', 15:46:27 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 15:46:27 INFO - '--firstNonBlankPaint'], 15:46:27 INFO - 'tests': ['tp6_google', 15:46:27 INFO - 'tp6_youtube', 15:46:27 INFO - 'tp6_amazon', 15:46:27 INFO - 'tp6_facebook']}, 15:46:27 INFO - 'tp6-stylo-threads-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 15:46:27 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 15:46:27 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 15:46:27 INFO - 'talos_options': ['--stylo-threads=1', 15:46:27 INFO - '--mitmproxy', 15:46:27 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 15:46:27 INFO - '--firstNonBlankPaint'], 15:46:27 INFO - 'tests': ['tp6_google', 15:46:27 INFO - 'tp6_youtube', 15:46:27 INFO - 'tp6_amazon', 15:46:27 INFO - 'tp6_facebook']}, 15:46:27 INFO - 'xperf-e10s': {'pagesets_name': 'tp5n.zip', 15:46:27 INFO - 'talos_options': ['--xperf_path', 15:46:27 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 15:46:27 INFO - 'tests': ['tp5n']}, 15:46:27 INFO - 'xperf-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 15:46:27 INFO - 'talos_options': ['--disable-stylo', 15:46:27 INFO - '--xperf_path', 15:46:27 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 15:46:27 INFO - 'tests': ['tp5n']}}} 15:46:27 INFO - Running post-action listener: _resource_record_post_action 15:46:27 INFO - [mozharness: 2017-10-29 22:46:27.927443Z] Finished populate-webroot step (success) 15:46:27 INFO - [mozharness: 2017-10-29 22:46:27.927531Z] Running create-virtualenv step. 15:46:27 INFO - Running pre-action listener: _resource_record_pre_action 15:46:27 INFO - Running main action method: create_virtualenv 15:46:27 INFO - Creating virtualenv /builds/slave/test/build/venv 15:46:27 INFO - Running command: ['/tools/buildbot/bin/python', '/builds/slave/test/scripts/external_tools/virtualenv/virtualenv.py', '--always-copy', '/builds/slave/test/build/venv'] in /builds/slave/test/build 15:46:27 INFO - Copy/paste: /tools/buildbot/bin/python /builds/slave/test/scripts/external_tools/virtualenv/virtualenv.py --always-copy /builds/slave/test/build/venv 15:46:27 INFO - Using partial env: {'VIRTUALENV_NO_DOWNLOAD': '1'} 15:46:28 INFO - Using real prefix '/usr' 15:46:28 INFO - New python executable in /builds/slave/test/build/venv/bin/python 15:46:28 INFO - Overwriting /builds/slave/test/build/venv/lib/python2.7/distutils/__init__.py with new content 15:46:34 INFO - Installing setuptools, pip, wheel...done. 15:46:34 INFO - Return code: 0 15:46:34 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv 15:46:34 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.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://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 15:46:34 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 15:46:34 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.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://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 15:46:34 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 15:46:34 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'pip>=1.5']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x19ce1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b98a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1d3bcc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1d38e60>, '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 0x1d39d60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1d3a1f0>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 15:46:34 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'pip>=1.5'] in /builds/slave/test/build 15:46:34 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org pip>=1.5 15:46:34 INFO - Using env: {'DISPLAY': ':0', 15:46:34 INFO - 'HOME': '/home/cltbld', 15:46:34 INFO - 'LANG': 'en_US.UTF-8', 15:46:34 INFO - 'LANGUAGE': 'en_US:en', 15:46:34 INFO - 'LOGNAME': 'cltbld', 15:46:34 INFO - 'MAIL': '/var/mail/cltbld', 15:46:34 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 15:46:34 INFO - 'MOZ_NO_REMOTE': '1', 15:46:34 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 15:46:34 INFO - 'NO_EM_RESTART': '1', 15:46:34 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 15:46:34 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 15:46:34 INFO - 'PWD': '/builds/slave/test', 15:46:34 INFO - 'SHELL': '/bin/bash', 15:46:34 INFO - 'SHLVL': '1', 15:46:34 INFO - 'TERM': 'linux', 15:46:34 INFO - 'TMOUT': '86400', 15:46:34 INFO - 'USER': 'cltbld', 15:46:34 INFO - 'XDG_SESSION_COOKIE': '8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451', 15:46:34 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 15:46:34 INFO - '_': '/tools/buildbot/bin/python'} 15:46:35 INFO - Ignoring indexes: https://pypi.python.org/simple 15:46:38 INFO - Requirement already satisfied (use --upgrade to upgrade): pip>=1.5 in ./venv/lib/python2.7/site-packages 15:46:38 INFO - Return code: 0 15:46:38 INFO - Installing psutil>=3.1.1 into virtualenv /builds/slave/test/build/venv 15:46:38 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.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://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 15:46:38 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 15:46:38 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.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://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 15:46:38 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 15:46:38 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'psutil>=3.1.1']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x19ce1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b98a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1d3bcc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1d38e60>, '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 0x1d39d60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1d3a1f0>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 15:46:38 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'psutil>=3.1.1'] in /builds/slave/test/build 15:46:38 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org psutil>=3.1.1 15:46:38 INFO - Using env: {'DISPLAY': ':0', 15:46:38 INFO - 'HOME': '/home/cltbld', 15:46:38 INFO - 'LANG': 'en_US.UTF-8', 15:46:38 INFO - 'LANGUAGE': 'en_US:en', 15:46:38 INFO - 'LOGNAME': 'cltbld', 15:46:38 INFO - 'MAIL': '/var/mail/cltbld', 15:46:38 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 15:46:38 INFO - 'MOZ_NO_REMOTE': '1', 15:46:38 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 15:46:38 INFO - 'NO_EM_RESTART': '1', 15:46:38 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 15:46:38 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 15:46:38 INFO - 'PWD': '/builds/slave/test', 15:46:38 INFO - 'SHELL': '/bin/bash', 15:46:38 INFO - 'SHLVL': '1', 15:46:38 INFO - 'TERM': 'linux', 15:46:38 INFO - 'TMOUT': '86400', 15:46:38 INFO - 'USER': 'cltbld', 15:46:38 INFO - 'XDG_SESSION_COOKIE': '8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451', 15:46:38 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 15:46:38 INFO - '_': '/tools/buildbot/bin/python'} 15:46:38 INFO - Ignoring indexes: https://pypi.python.org/simple 15:46:38 INFO - Collecting psutil>=3.1.1 15:46:39 INFO - Installing collected packages: psutil 15:46:43 INFO - Successfully installed psutil-3.1.1 15:46:43 INFO - Return code: 0 15:46:43 INFO - Installing mozsystemmonitor==0.3 into virtualenv /builds/slave/test/build/venv 15:46:43 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.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://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 15:46:43 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 15:46:43 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.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://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 15:46:43 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 15:46:43 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'mozsystemmonitor==0.3']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x19ce1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b98a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1d3bcc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1d38e60>, '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 0x1d39d60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1d3a1f0>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 15:46:43 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'mozsystemmonitor==0.3'] in /builds/slave/test/build 15:46:43 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org mozsystemmonitor==0.3 15:46:43 INFO - Using env: {'DISPLAY': ':0', 15:46:43 INFO - 'HOME': '/home/cltbld', 15:46:43 INFO - 'LANG': 'en_US.UTF-8', 15:46:43 INFO - 'LANGUAGE': 'en_US:en', 15:46:43 INFO - 'LOGNAME': 'cltbld', 15:46:43 INFO - 'MAIL': '/var/mail/cltbld', 15:46:43 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 15:46:43 INFO - 'MOZ_NO_REMOTE': '1', 15:46:43 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 15:46:43 INFO - 'NO_EM_RESTART': '1', 15:46:43 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 15:46:43 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 15:46:43 INFO - 'PWD': '/builds/slave/test', 15:46:43 INFO - 'SHELL': '/bin/bash', 15:46:43 INFO - 'SHLVL': '1', 15:46:43 INFO - 'TERM': 'linux', 15:46:43 INFO - 'TMOUT': '86400', 15:46:43 INFO - 'USER': 'cltbld', 15:46:43 INFO - 'XDG_SESSION_COOKIE': '8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451', 15:46:43 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 15:46:43 INFO - '_': '/tools/buildbot/bin/python'} 15:46:43 INFO - Ignoring indexes: https://pypi.python.org/simple 15:46:44 INFO - Collecting mozsystemmonitor==0.3 15:46:45 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.3) 15:46:45 INFO - Installing collected packages: mozsystemmonitor 15:46:45 INFO - Successfully installed mozsystemmonitor-0.3 15:46:45 INFO - Return code: 0 15:46:45 INFO - Installing jsonschema==2.5.1 into virtualenv /builds/slave/test/build/venv 15:46:45 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.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://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 15:46:45 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 15:46:45 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.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://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 15:46:45 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 15:46:45 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'jsonschema==2.5.1']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x19ce1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b98a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1d3bcc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1d38e60>, '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 0x1d39d60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1d3a1f0>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 15:46:45 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'jsonschema==2.5.1'] in /builds/slave/test/build 15:46:45 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org jsonschema==2.5.1 15:46:45 INFO - Using env: {'DISPLAY': ':0', 15:46:45 INFO - 'HOME': '/home/cltbld', 15:46:45 INFO - 'LANG': 'en_US.UTF-8', 15:46:45 INFO - 'LANGUAGE': 'en_US:en', 15:46:45 INFO - 'LOGNAME': 'cltbld', 15:46:45 INFO - 'MAIL': '/var/mail/cltbld', 15:46:45 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 15:46:45 INFO - 'MOZ_NO_REMOTE': '1', 15:46:45 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 15:46:45 INFO - 'NO_EM_RESTART': '1', 15:46:45 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 15:46:45 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 15:46:45 INFO - 'PWD': '/builds/slave/test', 15:46:45 INFO - 'SHELL': '/bin/bash', 15:46:45 INFO - 'SHLVL': '1', 15:46:45 INFO - 'TERM': 'linux', 15:46:45 INFO - 'TMOUT': '86400', 15:46:45 INFO - 'USER': 'cltbld', 15:46:45 INFO - 'XDG_SESSION_COOKIE': '8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451', 15:46:45 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 15:46:45 INFO - '_': '/tools/buildbot/bin/python'} 15:46:46 INFO - Ignoring indexes: https://pypi.python.org/simple 15:46:46 INFO - Collecting jsonschema==2.5.1 15:46:47 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/jsonschema-2.5.1-py2.py3-none-any.whl 15:46:47 INFO - Collecting functools32; python_version == "2.7" (from jsonschema==2.5.1) 15:46:48 INFO - Installing collected packages: functools32, jsonschema 15:46:48 INFO - Successfully installed functools32-3.2.3.post2 jsonschema-2.5.1 15:46:48 INFO - Return code: 0 15:46:48 INFO - Installing functools32==3.2.3-2 into virtualenv /builds/slave/test/build/venv 15:46:48 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.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://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 15:46:48 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 15:46:48 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.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://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 15:46:48 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 15:46:48 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'functools32==3.2.3-2']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x19ce1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b98a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1d3bcc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1d38e60>, '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 0x1d39d60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1d3a1f0>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 15:46:48 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'functools32==3.2.3-2'] in /builds/slave/test/build 15:46:48 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org functools32==3.2.3-2 15:46:48 INFO - Using env: {'DISPLAY': ':0', 15:46:48 INFO - 'HOME': '/home/cltbld', 15:46:48 INFO - 'LANG': 'en_US.UTF-8', 15:46:48 INFO - 'LANGUAGE': 'en_US:en', 15:46:48 INFO - 'LOGNAME': 'cltbld', 15:46:48 INFO - 'MAIL': '/var/mail/cltbld', 15:46:48 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 15:46:48 INFO - 'MOZ_NO_REMOTE': '1', 15:46:48 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 15:46:48 INFO - 'NO_EM_RESTART': '1', 15:46:48 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 15:46:48 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 15:46:48 INFO - 'PWD': '/builds/slave/test', 15:46:48 INFO - 'SHELL': '/bin/bash', 15:46:48 INFO - 'SHLVL': '1', 15:46:48 INFO - 'TERM': 'linux', 15:46:48 INFO - 'TMOUT': '86400', 15:46:48 INFO - 'USER': 'cltbld', 15:46:48 INFO - 'XDG_SESSION_COOKIE': '8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451', 15:46:48 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 15:46:48 INFO - '_': '/tools/buildbot/bin/python'} 15:46:48 INFO - Ignoring indexes: https://pypi.python.org/simple 15:46:48 INFO - Requirement already satisfied (use --upgrade to upgrade): functools32==3.2.3-2 in ./venv/lib/python2.7/site-packages 15:46:48 INFO - Return code: 0 15:46:48 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv 15:46:48 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.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://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 15:46:48 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 15:46:48 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.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://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 15:46:48 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 15:46:48 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', '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 0x19ce1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b98a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1d3bcc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1d38e60>, '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 0x1d39d60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1d3a1f0>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 15:46:48 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'blobuploader==1.2.4'] in /builds/slave/test/build 15:46:48 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org blobuploader==1.2.4 15:46:48 INFO - Using env: {'DISPLAY': ':0', 15:46:48 INFO - 'HOME': '/home/cltbld', 15:46:48 INFO - 'LANG': 'en_US.UTF-8', 15:46:48 INFO - 'LANGUAGE': 'en_US:en', 15:46:48 INFO - 'LOGNAME': 'cltbld', 15:46:48 INFO - 'MAIL': '/var/mail/cltbld', 15:46:48 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 15:46:48 INFO - 'MOZ_NO_REMOTE': '1', 15:46:48 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 15:46:48 INFO - 'NO_EM_RESTART': '1', 15:46:48 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 15:46:48 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 15:46:48 INFO - 'PWD': '/builds/slave/test', 15:46:48 INFO - 'SHELL': '/bin/bash', 15:46:48 INFO - 'SHLVL': '1', 15:46:48 INFO - 'TERM': 'linux', 15:46:48 INFO - 'TMOUT': '86400', 15:46:48 INFO - 'USER': 'cltbld', 15:46:48 INFO - 'XDG_SESSION_COOKIE': '8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451', 15:46:48 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 15:46:48 INFO - '_': '/tools/buildbot/bin/python'} 15:46:49 INFO - Ignoring indexes: https://pypi.python.org/simple 15:46:49 INFO - Collecting blobuploader==1.2.4 15:46:50 INFO - Collecting requests==1.2.3. (from blobuploader==1.2.4) 15:46:51 INFO - Collecting docopt==0.6.1 (from blobuploader==1.2.4) 15:46:52 INFO - Installing collected packages: requests, docopt, blobuploader 15:46:52 INFO - Successfully installed blobuploader-1.2.4 docopt-0.6.1 requests-1.2.3 15:46:52 INFO - Return code: 0 15:46:52 INFO - Installing None into virtualenv /builds/slave/test/build/venv 15:46:52 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.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://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 15:46:52 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 15:46:52 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.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://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 15:46:52 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 15:46:52 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x19ce1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b98a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1d3bcc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1d38e60>, '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 0x1d39d60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1d3a1f0>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build/tests/config', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 15:46:52 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org'] in /builds/slave/test/build/tests/config 15:46:52 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --no-deps --timeout 120 -r /builds/slave/test/build/tests/config/mozbase_requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org 15:46:52 INFO - Using env: {'DISPLAY': ':0', 15:46:52 INFO - 'HOME': '/home/cltbld', 15:46:52 INFO - 'LANG': 'en_US.UTF-8', 15:46:52 INFO - 'LANGUAGE': 'en_US:en', 15:46:52 INFO - 'LOGNAME': 'cltbld', 15:46:52 INFO - 'MAIL': '/var/mail/cltbld', 15:46:52 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 15:46:52 INFO - 'MOZ_NO_REMOTE': '1', 15:46:52 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 15:46:52 INFO - 'NO_EM_RESTART': '1', 15:46:52 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 15:46:52 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 15:46:52 INFO - 'PWD': '/builds/slave/test', 15:46:52 INFO - 'SHELL': '/bin/bash', 15:46:52 INFO - 'SHLVL': '1', 15:46:52 INFO - 'TERM': 'linux', 15:46:52 INFO - 'TMOUT': '86400', 15:46:52 INFO - 'USER': 'cltbld', 15:46:52 INFO - 'XDG_SESSION_COOKIE': '8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451', 15:46:52 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 15:46:52 INFO - '_': '/tools/buildbot/bin/python'} 15:46:53 INFO - Ignoring indexes: https://pypi.python.org/simple 15:46:53 INFO - Processing /builds/slave/test/build/tests/mozbase/manifestparser 15:46:53 INFO - Processing /builds/slave/test/build/tests/mozbase/mozcrash 15:46:53 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdebug 15:46:53 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdevice 15:46:53 INFO - Processing /builds/slave/test/build/tests/mozbase/mozfile 15:46:54 INFO - Processing /builds/slave/test/build/tests/mozbase/mozhttpd 15:46:54 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinfo 15:46:54 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinstall 15:46:54 INFO - Processing /builds/slave/test/build/tests/mozbase/mozleak 15:46:54 INFO - Processing /builds/slave/test/build/tests/mozbase/mozlog 15:46:54 INFO - Processing /builds/slave/test/build/tests/mozbase/moznetwork 15:46:55 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprocess 15:46:55 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprofile 15:46:55 INFO - Processing /builds/slave/test/build/tests/mozbase/mozrunner 15:46:55 INFO - Processing /builds/slave/test/build/tests/mozbase/mozscreenshot 15:46:55 INFO - Processing /builds/slave/test/build/tests/mozbase/moztest 15:46:56 INFO - Processing /builds/slave/test/build/tests/mozbase/mozversion 15:46:56 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion 15:46:56 INFO - Running setup.py install for manifestparser: started 15:46:56 INFO - Running setup.py install for manifestparser: finished with status 'done' 15:46:56 INFO - Running setup.py install for mozcrash: started 15:46:56 INFO - Running setup.py install for mozcrash: finished with status 'done' 15:46:56 INFO - Running setup.py install for mozdebug: started 15:46:56 INFO - Running setup.py install for mozdebug: finished with status 'done' 15:46:56 INFO - Running setup.py install for mozdevice: started 15:46:57 INFO - Running setup.py install for mozdevice: finished with status 'done' 15:46:57 INFO - Running setup.py install for mozfile: started 15:46:57 INFO - Running setup.py install for mozfile: finished with status 'done' 15:46:57 INFO - Running setup.py install for mozhttpd: started 15:46:57 INFO - Running setup.py install for mozhttpd: finished with status 'done' 15:46:57 INFO - Running setup.py install for mozinfo: started 15:46:57 INFO - Running setup.py install for mozinfo: finished with status 'done' 15:46:57 INFO - Running setup.py install for mozInstall: started 15:46:57 INFO - Running setup.py install for mozInstall: finished with status 'done' 15:46:57 INFO - Running setup.py install for mozleak: started 15:46:58 INFO - Running setup.py install for mozleak: finished with status 'done' 15:46:58 INFO - Running setup.py install for mozlog: started 15:46:58 INFO - Running setup.py install for mozlog: finished with status 'done' 15:46:58 INFO - Running setup.py install for moznetwork: started 15:46:58 INFO - Running setup.py install for moznetwork: finished with status 'done' 15:46:58 INFO - Running setup.py install for mozprocess: started 15:46:58 INFO - Running setup.py install for mozprocess: finished with status 'done' 15:46:58 INFO - Running setup.py install for mozprofile: started 15:46:59 INFO - Running setup.py install for mozprofile: finished with status 'done' 15:46:59 INFO - Running setup.py install for mozrunner: started 15:46:59 INFO - Running setup.py install for mozrunner: finished with status 'done' 15:46:59 INFO - Running setup.py install for mozscreenshot: started 15:46:59 INFO - Running setup.py install for mozscreenshot: finished with status 'done' 15:46:59 INFO - Running setup.py install for moztest: started 15:46:59 INFO - Running setup.py install for moztest: finished with status 'done' 15:46:59 INFO - Running setup.py install for mozversion: started 15:47:00 INFO - Running setup.py install for mozversion: finished with status 'done' 15:47:00 INFO - Successfully installed manifestparser-1.2 mozInstall-1.14 mozcrash-1.0 mozdebug-0.1 mozdevice-0.51 mozfile-1.2 mozhttpd-0.7 mozinfo-0.10 mozleak-0.1 mozlog-3.5 moznetwork-0.27 mozprocess-0.25 mozprofile-0.29 mozrunner-6.13 mozscreenshot-0.1 moztest-0.8 mozversion-1.4 15:47:00 INFO - Return code: 0 15:47:00 INFO - Installing None into virtualenv /builds/slave/test/build/venv 15:47:00 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.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://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 15:47:00 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 15:47:00 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.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://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 15:47:00 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 15:47:00 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x19ce1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b98a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1d3bcc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1d38e60>, '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 0x1d39d60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1d3a1f0>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build/tests/config', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 15:47:00 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org'] in /builds/slave/test/build/tests/config 15:47:00 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 -r /builds/slave/test/build/tests/config/mozbase_requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org 15:47:00 INFO - Using env: {'DISPLAY': ':0', 15:47:00 INFO - 'HOME': '/home/cltbld', 15:47:00 INFO - 'LANG': 'en_US.UTF-8', 15:47:00 INFO - 'LANGUAGE': 'en_US:en', 15:47:00 INFO - 'LOGNAME': 'cltbld', 15:47:00 INFO - 'MAIL': '/var/mail/cltbld', 15:47:00 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 15:47:00 INFO - 'MOZ_NO_REMOTE': '1', 15:47:00 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 15:47:00 INFO - 'NO_EM_RESTART': '1', 15:47:00 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 15:47:00 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 15:47:00 INFO - 'PWD': '/builds/slave/test', 15:47:00 INFO - 'SHELL': '/bin/bash', 15:47:00 INFO - 'SHLVL': '1', 15:47:00 INFO - 'TERM': 'linux', 15:47:00 INFO - 'TMOUT': '86400', 15:47:00 INFO - 'USER': 'cltbld', 15:47:00 INFO - 'XDG_SESSION_COOKIE': '8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451', 15:47:00 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 15:47:00 INFO - '_': '/tools/buildbot/bin/python'} 15:47:00 INFO - Ignoring indexes: https://pypi.python.org/simple 15:47:00 INFO - Processing /builds/slave/test/build/tests/mozbase/manifestparser 15:47:00 INFO - Requirement already satisfied (use --upgrade to upgrade): manifestparser==1.2 from file:///builds/slave/test/build/tests/mozbase/manifestparser in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 1)) 15:47:00 INFO - Processing /builds/slave/test/build/tests/mozbase/mozcrash 15:47:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash==1.0 from file:///builds/slave/test/build/tests/mozbase/mozcrash in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2)) 15:47:01 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdebug 15:47:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdebug==0.1 from file:///builds/slave/test/build/tests/mozbase/mozdebug in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 3)) 15:47:01 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdevice 15:47:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdevice==0.51 from file:///builds/slave/test/build/tests/mozbase/mozdevice in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4)) 15:47:01 INFO - Processing /builds/slave/test/build/tests/mozbase/mozfile 15:47:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile==1.2 from file:///builds/slave/test/build/tests/mozbase/mozfile in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 5)) 15:47:01 INFO - Processing /builds/slave/test/build/tests/mozbase/mozhttpd 15:47:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd==0.7 from file:///builds/slave/test/build/tests/mozbase/mozhttpd in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 6)) 15:47:01 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinfo 15:47:02 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo==0.10 from file:///builds/slave/test/build/tests/mozbase/mozinfo in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 7)) 15:47:02 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinstall 15:47:02 INFO - Requirement already satisfied (use --upgrade to upgrade): mozInstall==1.14 from file:///builds/slave/test/build/tests/mozbase/mozinstall in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 8)) 15:47:02 INFO - Processing /builds/slave/test/build/tests/mozbase/mozleak 15:47:02 INFO - Requirement already satisfied (use --upgrade to upgrade): mozleak==0.1 from file:///builds/slave/test/build/tests/mozbase/mozleak in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 9)) 15:47:02 INFO - Processing /builds/slave/test/build/tests/mozbase/mozlog 15:47:02 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog==3.5 from file:///builds/slave/test/build/tests/mozbase/mozlog in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 15:47:02 INFO - Processing /builds/slave/test/build/tests/mozbase/moznetwork 15:47:03 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork==0.27 from file:///builds/slave/test/build/tests/mozbase/moznetwork in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 11)) 15:47:03 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprocess 15:47:03 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess==0.25 from file:///builds/slave/test/build/tests/mozbase/mozprocess in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 12)) 15:47:03 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprofile 15:47:03 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile==0.29 from file:///builds/slave/test/build/tests/mozbase/mozprofile in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 13)) 15:47:03 INFO - Processing /builds/slave/test/build/tests/mozbase/mozrunner 15:47:03 INFO - Requirement already satisfied (use --upgrade to upgrade): mozrunner==6.13 from file:///builds/slave/test/build/tests/mozbase/mozrunner in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 14)) 15:47:03 INFO - Processing /builds/slave/test/build/tests/mozbase/mozscreenshot 15:47:03 INFO - Requirement already satisfied (use --upgrade to upgrade): mozscreenshot==0.1 from file:///builds/slave/test/build/tests/mozbase/mozscreenshot in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 15)) 15:47:03 INFO - Processing /builds/slave/test/build/tests/mozbase/moztest 15:47:04 INFO - Requirement already satisfied (use --upgrade to upgrade): moztest==0.8 from file:///builds/slave/test/build/tests/mozbase/moztest in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 16)) 15:47:04 INFO - Processing /builds/slave/test/build/tests/mozbase/mozversion 15:47:04 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion==1.4 from file:///builds/slave/test/build/tests/mozbase/mozversion in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 17)) 15:47:04 INFO - Collecting six>=1.10.0 (from manifestparser==1.2->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 1)) 15:47:05 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/six-1.10.0-py2.py3-none-any.whl 15:47:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozcrash==1.0->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2)) 15:47:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozcrash==1.0->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2)) 15:47:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozdebug==0.1->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 3)) 15:47:05 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork>=0.24 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozdevice==0.51->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4)) 15:47:05 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.19 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozdevice==0.51->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4)) 15:47:05 INFO - Requirement already satisfied (use --upgrade to upgrade): requests in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozInstall==1.14->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 8)) 15:47:05 INFO - Collecting blessings>=1.3 (from mozlog==3.5->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 15:47:06 INFO - Installing collected packages: six, blessings 15:47:07 INFO - Successfully installed blessings-1.6 six-1.10.0 15:47:07 INFO - Return code: 0 15:47:07 INFO - Done creating virtualenv /builds/slave/test/build/venv. 15:47:07 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 15:47:07 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 15:47:07 INFO - Reading from file tmpfile_stdout 15:47:07 INFO - Reading from file tmpfile_stderr 15:47:07 INFO - Current package versions: 15:47:07 INFO - blessings == 1.6 15:47:07 INFO - blobuploader == 1.2.4 15:47:07 INFO - docopt == 0.6.1 15:47:07 INFO - functools32 == 3.2.3.post2 15:47:07 INFO - jsonschema == 2.5.1 15:47:07 INFO - manifestparser == 1.2 15:47:07 INFO - mozInstall == 1.14 15:47:07 INFO - mozcrash == 1.0 15:47:07 INFO - mozdebug == 0.1 15:47:07 INFO - mozdevice == 0.51 15:47:07 INFO - mozfile == 1.2 15:47:07 INFO - mozhttpd == 0.7 15:47:07 INFO - mozinfo == 0.10 15:47:07 INFO - mozleak == 0.1 15:47:07 INFO - mozlog == 3.5 15:47:07 INFO - moznetwork == 0.27 15:47:07 INFO - mozprocess == 0.25 15:47:07 INFO - mozprofile == 0.29 15:47:07 INFO - mozrunner == 6.13 15:47:07 INFO - mozscreenshot == 0.1 15:47:07 INFO - mozsystemmonitor == 0.3 15:47:07 INFO - moztest == 0.8 15:47:07 INFO - mozversion == 1.4 15:47:07 INFO - psutil == 3.1.1 15:47:07 INFO - requests == 1.2.3 15:47:07 INFO - six == 1.10.0 15:47:07 INFO - Installing None into virtualenv /builds/slave/test/build/venv 15:47:07 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.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://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 15:47:07 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 15:47:07 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.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://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 15:47:07 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 15:47:07 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '-r', '/builds/slave/test/build/tests/talos/requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x19ce1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b98a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1d3bcc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1d38e60>, '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 0x1d39d60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1d3a1f0>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build/tests/talos', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 15:47:07 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '-r', '/builds/slave/test/build/tests/talos/requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org'] in /builds/slave/test/build/tests/talos 15:47:07 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 -r /builds/slave/test/build/tests/talos/requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org 15:47:07 INFO - Using env: {'DISPLAY': ':0', 15:47:07 INFO - 'HOME': '/home/cltbld', 15:47:07 INFO - 'LANG': 'en_US.UTF-8', 15:47:07 INFO - 'LANGUAGE': 'en_US:en', 15:47:07 INFO - 'LOGNAME': 'cltbld', 15:47:07 INFO - 'MAIL': '/var/mail/cltbld', 15:47:07 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 15:47:07 INFO - 'MOZ_NO_REMOTE': '1', 15:47:07 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 15:47:07 INFO - 'NO_EM_RESTART': '1', 15:47:07 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 15:47:07 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 15:47:07 INFO - 'PWD': '/builds/slave/test', 15:47:07 INFO - 'SHELL': '/bin/bash', 15:47:07 INFO - 'SHLVL': '1', 15:47:07 INFO - 'TERM': 'linux', 15:47:07 INFO - 'TMOUT': '86400', 15:47:07 INFO - 'USER': 'cltbld', 15:47:07 INFO - 'XDG_SESSION_COOKIE': '8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451', 15:47:07 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 15:47:07 INFO - '_': '/tools/buildbot/bin/python'} 15:47:08 INFO - Ignoring indexes: https://pypi.python.org/simple 15:47:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.1 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 1)) 15:47:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash>=0.15 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 2)) 15:47:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.2 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 3)) 15:47:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd>=0.7 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 4)) 15:47:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo>=0.8 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 5)) 15:47:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.22 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 6)) 15:47:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion>=1.3 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 7)) 15:47:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile>=0.25 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 8)) 15:47:08 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 9)) 15:47:08 INFO - Collecting simplejson>=2.1.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 10)) 15:47:09 INFO - Collecting requests>=2.9.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 15:47:10 INFO - Requirement already satisfied (use --upgrade to upgrade): blessings>=1.3 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozlog>=3.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 1)) 15:47:10 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork>=0.24 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozhttpd>=0.7->-r /builds/slave/test/build/tests/talos/requirements.txt (line 4)) 15:47:10 INFO - Requirement already satisfied (use --upgrade to upgrade): six>=1.10.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozprofile>=0.25->-r /builds/slave/test/build/tests/talos/requirements.txt (line 8)) 15:47:10 INFO - Installing collected packages: simplejson, requests 15:47:10 INFO - Found existing installation: requests 1.2.3 15:47:10 INFO - Uninstalling requests-1.2.3: 15:47:10 INFO - Successfully uninstalled requests-1.2.3 15:47:10 INFO - Successfully installed requests-2.13.0 simplejson-3.3.0 15:47:10 INFO - Return code: 0 15:47:10 INFO - Installing jsonschema into virtualenv /builds/slave/test/build/venv 15:47:10 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.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://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 15:47:10 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 15:47:10 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.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://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 15:47:10 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 15:47:10 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'jsonschema']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x19ce1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b98a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1d3bcc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1d38e60>, '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 0x1d39d60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1d3a1f0>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 15:47:10 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'jsonschema'] in /builds/slave/test/build 15:47:10 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org jsonschema 15:47:10 INFO - Using env: {'DISPLAY': ':0', 15:47:10 INFO - 'HOME': '/home/cltbld', 15:47:10 INFO - 'LANG': 'en_US.UTF-8', 15:47:10 INFO - 'LANGUAGE': 'en_US:en', 15:47:10 INFO - 'LOGNAME': 'cltbld', 15:47:10 INFO - 'MAIL': '/var/mail/cltbld', 15:47:10 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 15:47:10 INFO - 'MOZ_NO_REMOTE': '1', 15:47:10 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 15:47:10 INFO - 'NO_EM_RESTART': '1', 15:47:10 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 15:47:10 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 15:47:10 INFO - 'PWD': '/builds/slave/test', 15:47:10 INFO - 'SHELL': '/bin/bash', 15:47:10 INFO - 'SHLVL': '1', 15:47:10 INFO - 'TERM': 'linux', 15:47:10 INFO - 'TMOUT': '86400', 15:47:10 INFO - 'USER': 'cltbld', 15:47:10 INFO - 'XDG_SESSION_COOKIE': '8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451', 15:47:10 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 15:47:10 INFO - '_': '/tools/buildbot/bin/python'} 15:47:11 INFO - Ignoring indexes: https://pypi.python.org/simple 15:47:11 INFO - Requirement already satisfied (use --upgrade to upgrade): jsonschema in ./venv/lib/python2.7/site-packages 15:47:11 INFO - Requirement already satisfied (use --upgrade to upgrade): functools32; python_version == "2.7" in ./venv/lib/python2.7/site-packages (from jsonschema) 15:47:11 INFO - Return code: 0 15:47:11 INFO - Running post-action listener: _resource_record_post_action 15:47:11 INFO - Running post-action listener: _start_resource_monitoring 15:47:11 INFO - Starting resource monitoring. 15:47:11 INFO - [mozharness: 2017-10-29 22:47:11.311264Z] Finished create-virtualenv step (success) 15:47:11 INFO - [mozharness: 2017-10-29 22:47:11.311772Z] Running install step. 15:47:11 INFO - Running pre-action listener: _resource_record_pre_action 15:47:11 INFO - Running main action method: install 15:47:11 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 15:47:11 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 15:47:11 INFO - Reading from file tmpfile_stdout 15:47:11 INFO - Reading from file tmpfile_stderr 15:47:11 INFO - Detecting whether we're running mozinstall >=1.0... 15:47:11 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h'] 15:47:11 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h 15:47:12 INFO - Reading from file tmpfile_stdout 15:47:12 INFO - Output received: 15:47:12 INFO - Usage: mozinstall [options] installer 15:47:12 INFO - Options: 15:47:12 INFO - -h, --help show this help message and exit 15:47:12 INFO - -d DEST, --destination=DEST 15:47:12 INFO - Directory to install application into. [default: 15:47:12 INFO - "/builds/slave/test"] 15:47:12 INFO - --app=APP Application being installed. [default: firefox] 15:47:12 INFO - mkdir: /builds/slave/test/build/application 15:47:12 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '/builds/slave/test/build/target.tar.bz2', '--destination', '/builds/slave/test/build/application'] 15:47:12 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall /builds/slave/test/build/target.tar.bz2 --destination /builds/slave/test/build/application 15:47:30 INFO - Reading from file tmpfile_stdout 15:47:30 INFO - Output received: 15:47:30 INFO - /builds/slave/test/build/application/firefox/firefox 15:47:30 INFO - Running post-action listener: _resource_record_post_action 15:47:30 INFO - [mozharness: 2017-10-29 22:47:30.240042Z] Finished install step (success) 15:47:30 INFO - [mozharness: 2017-10-29 22:47:30.240375Z] Running setup-mitmproxy step. 15:47:30 INFO - Running pre-action listener: _resource_record_pre_action 15:47:30 INFO - Running main action method: setup_mitmproxy 15:47:30 INFO - Skipping: mitmproxy is not required 15:47:30 INFO - Running post-action listener: _resource_record_post_action 15:47:30 INFO - [mozharness: 2017-10-29 22:47:30.242060Z] Finished setup-mitmproxy step (success) 15:47:30 INFO - [mozharness: 2017-10-29 22:47:30.242363Z] Running run-tests step. 15:47:30 INFO - Running pre-action listener: _resource_record_pre_action 15:47:30 INFO - Running pre-action listener: _set_gcov_prefix 15:47:30 INFO - Running main action method: run_tests 15:47:30 WARNING - Try message not found. 15:47:30 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version'] 15:47:30 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version 15:47:30 INFO - Python 2.7.3 15:47:30 INFO - Return code: 0 15:47:30 INFO - grabbing minidump binary from tooltool 15:47:30 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.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://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 15:47:30 INFO - retry: Calling run_command with args: (['/tools/tooltool.py', '--url', 'https://tooltool.mozilla-releng.net/', '--authentication-file', '/builds/relengapi.tok', 'fetch', '-m', '/builds/slave/test/build/tests/config/tooltool-manifests/linux64/releng.manifest', '-o', '-c', '/builds/tooltool_cache'],), kwargs: {'output_timeout': 600, 'error_list': [{'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1d38e60>, '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 0x1d39d60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1d3a1f0>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1 15:47:30 INFO - Running command: ['/tools/tooltool.py', '--url', 'https://tooltool.mozilla-releng.net/', '--authentication-file', '/builds/relengapi.tok', 'fetch', '-m', '/builds/slave/test/build/tests/config/tooltool-manifests/linux64/releng.manifest', '-o', '-c', '/builds/tooltool_cache'] in /builds/slave/test/build 15:47:30 INFO - Copy/paste: /tools/tooltool.py --url https://tooltool.mozilla-releng.net/ --authentication-file /builds/relengapi.tok fetch -m /builds/slave/test/build/tests/config/tooltool-manifests/linux64/releng.manifest -o -c /builds/tooltool_cache 15:47:30 INFO - Calling ['/tools/tooltool.py', '--url', 'https://tooltool.mozilla-releng.net/', '--authentication-file', '/builds/relengapi.tok', 'fetch', '-m', '/builds/slave/test/build/tests/config/tooltool-manifests/linux64/releng.manifest', '-o', '-c', '/builds/tooltool_cache'] with output_timeout 600 15:47:30 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache 15:47:30 INFO - Return code: 0 15:47:30 INFO - Chmoding /builds/slave/test/build/linux64-minidump_stackwalk to 0755 15:47:30 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir 15:47:30 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir 15:47:30 INFO - ENV: RUST_BACKTRACE is now full 15:47:30 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/linux64-minidump_stackwalk 15:47:30 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir 15:47:30 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--branchName', 'Firefox-Non-PGO', '--suite', 'g4-e10s', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/QMTqhJs6Rr-6xXFHz6mTCQ/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-038', '--webServer', 'localhost', '--log-tbpl-level=debug', '--log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-e10s_errorsummary.log', '--log-raw=/builds/slave/test/build/blobber_upload_dir/g4-e10s_raw.log'] in /builds/slave/test/build 15:47:30 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/tests/talos/talos/run_tests.py --branchName Firefox-Non-PGO --suite g4-e10s --executablePath /builds/slave/test/build/application/firefox/firefox --symbolsPath https://queue.taskcluster.net/v1/task/QMTqhJs6Rr-6xXFHz6mTCQ/artifacts/public/build/target.crashreporter-symbols.zip --title talos-linux64-ix-038 --webServer localhost --log-tbpl-level=debug --log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-e10s_errorsummary.log --log-raw=/builds/slave/test/build/blobber_upload_dir/g4-e10s_raw.log 15:47:30 INFO - Using env: {'DISPLAY': ':0', 15:47:30 INFO - 'HOME': '/home/cltbld', 15:47:30 INFO - 'LANG': 'en_US.UTF-8', 15:47:30 INFO - 'LANGUAGE': 'en_US:en', 15:47:30 INFO - 'LOGNAME': 'cltbld', 15:47:30 INFO - 'MAIL': '/var/mail/cltbld', 15:47:30 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 15:47:30 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 15:47:30 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 15:47:30 INFO - 'MOZ_NO_REMOTE': '1', 15:47:30 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 15:47:30 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 15:47:30 INFO - 'NO_EM_RESTART': '1', 15:47:30 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 15:47:30 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 15:47:30 INFO - 'PWD': '/builds/slave/test', 15:47:30 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 15:47:30 INFO - 'RUST_BACKTRACE': 'full', 15:47:30 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 15:47:30 INFO - 'SHELL': '/bin/bash', 15:47:30 INFO - 'SHLVL': '1', 15:47:30 INFO - 'TERM': 'linux', 15:47:30 INFO - 'TMOUT': '86400', 15:47:30 INFO - 'USER': 'cltbld', 15:47:30 INFO - 'XDG_SESSION_COOKIE': '8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451', 15:47:30 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 15:47:30 INFO - '_': '/tools/buildbot/bin/python'} 15:47:30 INFO - Calling ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--branchName', 'Firefox-Non-PGO', '--suite', 'g4-e10s', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/QMTqhJs6Rr-6xXFHz6mTCQ/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-038', '--webServer', 'localhost', '--log-tbpl-level=debug', '--log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-e10s_errorsummary.log', '--log-raw=/builds/slave/test/build/blobber_upload_dir/g4-e10s_raw.log'] with output_timeout 3600 15:47:30 INFO - mozversion application_buildid: 20171029215112 15:47:30 INFO - mozversion application_changeset: 09cdea082e9abee362b89d8ab6ca9c8b282583d8 15:47:30 INFO - mozversion application_display_name: Nightly 15:47:30 INFO - mozversion application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384} 15:47:30 INFO - mozversion application_name: Firefox 15:47:30 INFO - mozversion application_remotingname: firefox 15:47:30 INFO - mozversion application_repository: https://hg.mozilla.org/mozilla-central 15:47:30 INFO - mozversion application_vendor: Mozilla 15:47:30 INFO - mozversion application_version: 58.0a1 15:47:30 INFO - mozversion platform_buildid: 20171029215112 15:47:30 INFO - mozversion platform_changeset: 09cdea082e9abee362b89d8ab6ca9c8b282583d8 15:47:30 INFO - mozversion platform_repository: https://hg.mozilla.org/mozilla-central 15:47:30 INFO - mozversion platform_version: 58.0a1 15:47:30 INFO - using testdate: 1509317250 15:47:30 INFO - actual date: 1509317250 15:47:30 INFO - starting webserver on 'localhost:36758' 15:47:30 INFO - SUITE-START | Running 2 tests 15:47:30 INFO - TEST-START | basic_compositor_video 15:47:30 INFO - Initialising browser for basic_compositor_video test... 15:47:30 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:36758/getInfo.html -profile /tmp/tmpBhy1JI/profile 15:47:30 INFO - TEST-INFO | started process 24540 (/builds/slave/test/build/application/firefox/firefox http://localhost:36758/getInfo.html) 15:47:37 INFO - TEST-INFO | 24540: exit 0 15:47:37 INFO - Browser initialized. 15:47:37 INFO - Running cycle 1/1 for basic_compositor_video test... 15:47:37 INFO - Using env: {'DISPLAY': ':0', 15:47:37 INFO - 'HOME': '/home/cltbld', 15:47:37 INFO - 'JSGC_DISABLE_POISONING': '1', 15:47:37 INFO - 'LANG': 'en_US.UTF-8', 15:47:37 INFO - 'LANGUAGE': 'en_US:en', 15:47:37 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 15:47:37 INFO - 'LOGNAME': 'cltbld', 15:47:37 INFO - 'MAIL': '/var/mail/cltbld', 15:47:37 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 15:47:37 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 15:47:37 INFO - 'MOZ_CRASHREPORTER': '1', 15:47:37 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 15:47:37 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 15:47:37 INFO - 'MOZ_NO_REMOTE': '1', 15:47:37 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 15:47:37 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 15:47:37 INFO - 'NO_EM_RESTART': '1', 15:47:37 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 15:47:37 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 15:47:37 INFO - 'PWD': '/builds/slave/test', 15:47:37 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 15:47:37 INFO - 'RUST_BACKTRACE': 'full', 15:47:37 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 15:47:37 INFO - 'SHELL': '/bin/bash', 15:47:37 INFO - 'SHLVL': '1', 15:47:37 INFO - 'TERM': 'linux', 15:47:37 INFO - 'TMOUT': '86400', 15:47:37 INFO - 'USER': 'cltbld', 15:47:37 INFO - 'XDG_SESSION_COOKIE': '8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451', 15:47:37 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 15:47:37 INFO - '_': '/tools/buildbot/bin/python'} 15:47:37 INFO - TEST-INFO | started process 24814 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpBhy1JI/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/video/video.manifest.develop -tpnoisy -tpcycles 1 -tppagecycles 12) 15:47:38 INFO - PID 24814 | 15:47:38 INFO - PID 24814 | (/builds/slave/test/build/application/firefox/firefox:24865): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 15:47:38 INFO - PID 24814 | 15:48:24 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6865767284991569 ms/frame 15:48:24 INFO - PID 24814 | 15:48:24 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6700417362270448 ms/frame 15:48:24 INFO - PID 24814 | 15:48:24 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7742519219396808 ms/frame 15:48:24 INFO - PID 24814 | 15:48:24 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.731688311688312 ms/frame 15:48:24 INFO - PID 24814 | 15:48:24 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_2_startup = 3.9483684210526295 ms/frame 15:48:24 INFO - PID 24814 | 15:48:24 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.185355648535565 ms/frame 15:48:24 INFO - PID 24814 | 15:48:24 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1_startup = 3.46019607843137 ms/frame 15:48:24 INFO - PID 24814 | 15:48:24 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3334250000000005 ms/frame 15:48:24 INFO - PID 24814 | 15:48:24 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1.1_startup = 3.5847132616487443 ms/frame 15:48:24 INFO - PID 24814 | 15:48:24 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1.1_inclip = 3.9766302186878706 ms/frame 15:48:24 INFO - PID 24814 | 15:48:24 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_2_startup = 9.61892628205128 ms/frame 15:48:24 INFO - PID 24814 | 15:48:24 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_2_inclip = 9.6671497584541 ms/frame 15:48:24 INFO - PID 24814 | 15:48:24 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.76482352941176 ms/frame 15:48:24 INFO - PID 24814 | 15:48:24 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.869619565217402 ms/frame 15:48:24 INFO - PID 24814 | 15:48:24 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.29959016393442 ms/frame 15:48:24 INFO - PID 24814 | 15:48:24 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.837810650887596 ms/frame 15:48:24 INFO - PID 24814 | 15:48:24 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.409980988593173 ms/frame 15:48:24 INFO - PID 24814 | 15:48:24 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.93322404371584 ms/frame 15:48:24 INFO - PID 24814 | 15:48:24 INFO - PID 24814 | Cycle 1(1): loaded http://localhost:36758/tests/video/video_playback.html (next: http://localhost:36758/tests/video/video_playback.html) 15:49:10 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1_startup = 1.686424957841484 ms/frame 15:49:10 INFO - PID 24814 | 15:49:10 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6694782971619364 ms/frame 15:49:10 INFO - PID 24814 | 15:49:10 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7641093474426808 ms/frame 15:49:10 INFO - PID 24814 | 15:49:10 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7560096575943804 ms/frame 15:49:10 INFO - PID 24814 | 15:49:10 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_2_startup = 4.133305785123965 ms/frame 15:49:10 INFO - PID 24814 | 15:49:10 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.937716535433072 ms/frame 15:49:10 INFO - PID 24814 | 15:49:10 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1_startup = 3.50100933488915 ms/frame 15:49:10 INFO - PID 24814 | 15:49:10 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1_inclip = 3.431097770154371 ms/frame 15:49:10 INFO - PID 24814 | 15:49:10 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.736864244741875 ms/frame 15:49:10 INFO - PID 24814 | 15:49:10 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.572144846796661 ms/frame 15:49:10 INFO - PID 24814 | 15:49:10 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_2_startup = 9.742808441558452 ms/frame 15:49:10 INFO - PID 24814 | 15:49:10 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_2_inclip = 9.712791262135918 ms/frame 15:49:10 INFO - PID 24814 | 15:49:10 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.366022727272732 ms/frame 15:49:10 INFO - PID 24814 | 15:49:10 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.933196721311484 ms/frame 15:49:10 INFO - PID 24814 | 15:49:10 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.60533613445378 ms/frame 15:49:10 INFO - PID 24814 | 15:49:10 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.906309523809536 ms/frame 15:49:10 INFO - PID 24814 | 15:49:10 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.451927480916027 ms/frame 15:49:10 INFO - PID 24814 | 15:49:10 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.115972222222222 ms/frame 15:49:10 INFO - PID 24814 | 15:49:10 INFO - PID 24814 | Cycle 1(2): loaded http://localhost:36758/tests/video/video_playback.html (next: http://localhost:36758/tests/video/video_playback.html) 15:49:56 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6830818844643858 ms/frame 15:49:56 INFO - PID 24814 | 15:49:56 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.67426359832636 ms/frame 15:49:56 INFO - PID 24814 | 15:49:56 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7397536231884057 ms/frame 15:49:56 INFO - PID 24814 | 15:49:56 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7348222029488292 ms/frame 15:49:56 INFO - PID 24814 | 15:49:56 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_2_startup = 4.167138888888889 ms/frame 15:49:56 INFO - PID 24814 | 15:49:56 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.229027484143763 ms/frame 15:49:56 INFO - PID 24814 | 15:49:56 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1_startup = 3.705049382716047 ms/frame 15:49:56 INFO - PID 24814 | 15:49:56 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1_inclip = 3.597500000000005 ms/frame 15:49:56 INFO - PID 24814 | 15:49:56 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.860644531250003 ms/frame 15:49:56 INFO - PID 24814 | 15:49:56 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.4209078590785875 ms/frame 15:49:56 INFO - PID 24814 | 15:49:56 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_2_startup = 10.205357142857142 ms/frame 15:49:56 INFO - PID 24814 | 15:49:56 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_2_inclip = 9.901881188118795 ms/frame 15:49:56 INFO - PID 24814 | 15:49:56 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.321962264150956 ms/frame 15:49:56 INFO - PID 24814 | 15:49:56 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.872907608695641 ms/frame 15:49:56 INFO - PID 24814 | 15:49:56 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.553430962343082 ms/frame 15:49:56 INFO - PID 24814 | 15:49:56 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.051626506024139 ms/frame 15:49:56 INFO - PID 24814 | 15:49:56 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.410247148288988 ms/frame 15:49:56 INFO - PID 24814 | 15:49:56 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.055303867403286 ms/frame 15:49:56 INFO - PID 24814 | 15:49:56 INFO - PID 24814 | Cycle 1(3): loaded http://localhost:36758/tests/video/video_playback.html (next: http://localhost:36758/tests/video/video_playback.html) 15:50:42 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6846715328467154 ms/frame 15:50:42 INFO - PID 24814 | 15:50:42 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6726463210702347 ms/frame 15:50:42 INFO - PID 24814 | 15:50:42 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.756841334894614 ms/frame 15:50:42 INFO - PID 24814 | 15:50:42 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.716828326180257 ms/frame 15:50:42 INFO - PID 24814 | 15:50:42 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_2_startup = 3.953498023715415 ms/frame 15:50:42 INFO - PID 24814 | 15:50:42 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.945552268244577 ms/frame 15:50:42 INFO - PID 24814 | 15:50:42 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1_startup = 3.6686308068459663 ms/frame 15:50:42 INFO - PID 24814 | 15:50:42 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1_inclip = 3.547101063829785 ms/frame 15:50:42 INFO - PID 24814 | 15:50:42 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.671947069943288 ms/frame 15:50:42 INFO - PID 24814 | 15:50:42 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.667096317280455 ms/frame 15:50:42 INFO - PID 24814 | 15:50:42 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_2_startup = 9.58626198083067 ms/frame 15:50:42 INFO - PID 24814 | 15:50:42 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_2_inclip = 9.136803652968032 ms/frame 15:50:42 INFO - PID 24814 | 15:50:42 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.583494208494194 ms/frame 15:50:42 INFO - PID 24814 | 15:50:42 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.995384615384635 ms/frame 15:50:42 INFO - PID 24814 | 15:50:42 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.452614107883795 ms/frame 15:50:42 INFO - PID 24814 | 15:50:42 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.497471264367844 ms/frame 15:50:42 INFO - PID 24814 | 15:50:42 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.953386454183278 ms/frame 15:50:42 INFO - PID 24814 | 15:50:42 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.176899441340787 ms/frame 15:50:42 INFO - PID 24814 | 15:50:42 INFO - PID 24814 | Cycle 1(4): loaded http://localhost:36758/tests/video/video_playback.html (next: http://localhost:36758/tests/video/video_playback.html) 15:51:29 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6846069623806852 ms/frame 15:51:29 INFO - PID 24814 | 15:51:29 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6705425709515855 ms/frame 15:51:29 INFO - PID 24814 | 15:51:29 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.766368452030606 ms/frame 15:51:29 INFO - PID 24814 | 15:51:29 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7747559893522624 ms/frame 15:51:29 INFO - PID 24814 | 15:51:29 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_2_startup = 4.156530470914129 ms/frame 15:51:29 INFO - PID 24814 | 15:51:29 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.14221532091097 ms/frame 15:51:29 INFO - PID 24814 | 15:51:29 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1_startup = 3.585179211469532 ms/frame 15:51:29 INFO - PID 24814 | 15:51:29 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1_inclip = 3.533701413427563 ms/frame 15:51:29 INFO - PID 24814 | 15:51:29 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.759692898272552 ms/frame 15:51:29 INFO - PID 24814 | 15:51:29 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.451989100817442 ms/frame 15:51:29 INFO - PID 24814 | 15:51:29 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_2_startup = 9.804232026143795 ms/frame 15:51:29 INFO - PID 24814 | 15:51:29 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_2_inclip = 9.713689320388351 ms/frame 15:51:29 INFO - PID 24814 | 15:51:29 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.4090494296578 ms/frame 15:51:29 INFO - PID 24814 | 15:51:29 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.871059782608704 ms/frame 15:51:29 INFO - PID 24814 | 15:51:29 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.397458677685972 ms/frame 15:51:29 INFO - PID 24814 | 15:51:29 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.43057142857142 ms/frame 15:51:29 INFO - PID 24814 | 15:51:29 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.495421455938699 ms/frame 15:51:29 INFO - PID 24814 | 15:51:29 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.815405405405398 ms/frame 15:51:29 INFO - PID 24814 | 15:51:29 INFO - PID 24814 | Cycle 1(5): loaded http://localhost:36758/tests/video/video_playback.html (next: http://localhost:36758/tests/video/video_playback.html) 15:52:15 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6831043185642176 ms/frame 15:52:15 INFO - PID 24814 | 15:52:15 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6705300500834726 ms/frame 15:52:15 INFO - PID 24814 | 15:52:15 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.75992082111437 ms/frame 15:52:15 INFO - PID 24814 | 15:52:15 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7908728737690232 ms/frame 15:52:15 INFO - PID 24814 | 15:52:15 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_2_startup = 4.027550335570469 ms/frame 15:52:15 INFO - PID 24814 | 15:52:15 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.151566390041494 ms/frame 15:52:15 INFO - PID 24814 | 15:52:15 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1_startup = 3.6240760869565203 ms/frame 15:52:15 INFO - PID 24814 | 15:52:15 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1_inclip = 3.546560283687947 ms/frame 15:52:15 INFO - PID 24814 | 15:52:15 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.7928281853281804 ms/frame 15:52:15 INFO - PID 24814 | 15:52:15 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.378172043010753 ms/frame 15:52:15 INFO - PID 24814 | 15:52:15 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_2_startup = 10.172016949152551 ms/frame 15:52:15 INFO - PID 24814 | 15:52:15 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_2_inclip = 9.952064676616905 ms/frame 15:52:15 INFO - PID 24814 | 15:52:15 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.4082699619772 ms/frame 15:52:15 INFO - PID 24814 | 15:52:15 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.706711229946517 ms/frame 15:52:15 INFO - PID 24814 | 15:52:15 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.448879668049793 ms/frame 15:52:15 INFO - PID 24814 | 15:52:15 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.98062874251501 ms/frame 15:52:15 INFO - PID 24814 | 15:52:15 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.407718631178719 ms/frame 15:52:15 INFO - PID 24814 | 15:52:15 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.934644808743174 ms/frame 15:52:15 INFO - PID 24814 | 15:52:15 INFO - PID 24814 | Cycle 1(6): loaded http://localhost:36758/tests/video/video_playback.html (next: http://localhost:36758/tests/video/video_playback.html) 15:52:38 INFO - PID 24814 | 15:52:38 INFO - PID 24814 | (/builds/slave/test/build/application/firefox/firefox:24947): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 15:52:38 INFO - PID 24814 | 15:53:01 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6809467787114847 ms/frame 15:53:01 INFO - PID 24814 | 15:53:01 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6728971571906353 ms/frame 15:53:01 INFO - PID 24814 | 15:53:01 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7396347826086955 ms/frame 15:53:01 INFO - PID 24814 | 15:53:01 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7454363001745197 ms/frame 15:53:01 INFO - PID 24814 | 15:53:01 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_2_startup = 4.231882933709448 ms/frame 15:53:01 INFO - PID 24814 | 15:53:01 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.185826359832637 ms/frame 15:53:01 INFO - PID 24814 | 15:53:01 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1_startup = 3.5018961493582283 ms/frame 15:53:01 INFO - PID 24814 | 15:53:01 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4134470989761074 ms/frame 15:53:01 INFO - PID 24814 | 15:53:01 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.536254612546128 ms/frame 15:53:01 INFO - PID 24814 | 15:53:01 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.4072432432432445 ms/frame 15:53:01 INFO - PID 24814 | 15:53:01 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_2_startup = 9.647877813504817 ms/frame 15:53:01 INFO - PID 24814 | 15:53:01 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_2_inclip = 10.104343434343434 ms/frame 15:53:01 INFO - PID 24814 | 15:53:01 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.58534749034749 ms/frame 15:53:01 INFO - PID 24814 | 15:53:01 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.872173913043456 ms/frame 15:53:01 INFO - PID 24814 | 15:53:01 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.397582644628084 ms/frame 15:53:01 INFO - PID 24814 | 15:53:01 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.910833333333358 ms/frame 15:53:01 INFO - PID 24814 | 15:53:01 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.630658914728679 ms/frame 15:53:01 INFO - PID 24814 | 15:53:01 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.116638888888904 ms/frame 15:53:01 INFO - PID 24814 | 15:53:01 INFO - PID 24814 | Cycle 1(7): loaded http://localhost:36758/tests/video/video_playback.html (next: http://localhost:36758/tests/video/video_playback.html) 15:53:47 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6839730639730641 ms/frame 15:53:47 INFO - PID 24814 | 15:53:47 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6730267558528429 ms/frame 15:53:47 INFO - PID 24814 | 15:53:47 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.8039927841250758 ms/frame 15:53:47 INFO - PID 24814 | 15:53:47 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7707876106194689 ms/frame 15:53:47 INFO - PID 24814 | 15:53:47 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_2_startup = 4.150013831258645 ms/frame 15:53:47 INFO - PID 24814 | 15:53:47 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.124938144329896 ms/frame 15:53:47 INFO - PID 24814 | 15:53:47 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1_startup = 3.5173329425556856 ms/frame 15:53:47 INFO - PID 24814 | 15:53:47 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4546459412780686 ms/frame 15:53:47 INFO - PID 24814 | 15:53:47 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.587085661080073 ms/frame 15:53:47 INFO - PID 24814 | 15:53:47 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.541454293628809 ms/frame 15:53:47 INFO - PID 24814 | 15:53:47 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_2_startup = 9.67891935483871 ms/frame 15:53:47 INFO - PID 24814 | 15:53:47 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_2_inclip = 9.904702970297029 ms/frame 15:53:47 INFO - PID 24814 | 15:53:47 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.542096153846138 ms/frame 15:53:47 INFO - PID 24814 | 15:53:47 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1_inclip = 11.0553867403315 ms/frame 15:53:47 INFO - PID 24814 | 15:53:47 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.714385593220344 ms/frame 15:53:47 INFO - PID 24814 | 15:53:47 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.837810650887553 ms/frame 15:53:47 INFO - PID 24814 | 15:53:47 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.321867924528295 ms/frame 15:53:47 INFO - PID 24814 | 15:53:47 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.815054054054073 ms/frame 15:53:47 INFO - PID 24814 | 15:53:47 INFO - PID 24814 | Cycle 1(8): loaded http://localhost:36758/tests/video/video_playback.html (next: http://localhost:36758/tests/video/video_playback.html) 15:54:33 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6857050561797755 ms/frame 15:54:33 INFO - PID 24814 | 15:54:33 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6739037656903761 ms/frame 15:54:33 INFO - PID 24814 | 15:54:33 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7826411170528815 ms/frame 15:54:33 INFO - PID 24814 | 15:54:33 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.728686257562663 ms/frame 15:54:33 INFO - PID 24814 | 15:54:33 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_2_startup = 3.9581728232189977 ms/frame 15:54:33 INFO - PID 24814 | 15:54:33 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.212494736842104 ms/frame 15:54:33 INFO - PID 24814 | 15:54:33 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1_startup = 3.537989386792451 ms/frame 15:54:33 INFO - PID 24814 | 15:54:33 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1_inclip = 3.5344699646643147 ms/frame 15:54:33 INFO - PID 24814 | 15:54:33 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.793272200772202 ms/frame 15:54:33 INFO - PID 24814 | 15:54:33 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.589636871508381 ms/frame 15:54:33 INFO - PID 24814 | 15:54:33 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_2_startup = 9.524079365079363 ms/frame 15:54:33 INFO - PID 24814 | 15:54:33 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_2_inclip = 10.10654040404041 ms/frame 15:54:33 INFO - PID 24814 | 15:54:33 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.409885931558932 ms/frame 15:54:33 INFO - PID 24814 | 15:54:33 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.991895604395612 ms/frame 15:54:33 INFO - PID 24814 | 15:54:33 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.55589958158993 ms/frame 15:54:33 INFO - PID 24814 | 15:54:33 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.128090909090922 ms/frame 15:54:33 INFO - PID 24814 | 15:54:33 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.453778625954197 ms/frame 15:54:33 INFO - PID 24814 | 15:54:33 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.813486486486461 ms/frame 15:54:33 INFO - PID 24814 | 15:54:33 INFO - PID 24814 | Cycle 1(9): loaded http://localhost:36758/tests/video/video_playback.html (next: http://localhost:36758/tests/video/video_playback.html) 15:55:20 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6926931754089114 ms/frame 15:55:20 INFO - PID 24814 | 15:55:20 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6727717391304349 ms/frame 15:55:20 INFO - PID 24814 | 15:55:20 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7744736842105264 ms/frame 15:55:20 INFO - PID 24814 | 15:55:20 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7629339207048453 ms/frame 15:55:20 INFO - PID 24814 | 15:55:20 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_2_startup = 4.184623430962343 ms/frame 15:55:20 INFO - PID 24814 | 15:55:20 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.158232848232846 ms/frame 15:55:20 INFO - PID 24814 | 15:55:20 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1_startup = 3.5514556213017725 ms/frame 15:55:20 INFO - PID 24814 | 15:55:20 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4603460207612486 ms/frame 15:55:20 INFO - PID 24814 | 15:55:20 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.66070754716981 ms/frame 15:55:20 INFO - PID 24814 | 15:55:20 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.589483240223463 ms/frame 15:55:20 INFO - PID 24814 | 15:55:20 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_2_startup = 10.3811937716263 ms/frame 15:55:20 INFO - PID 24814 | 15:55:20 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_2_inclip = 9.346238317756997 ms/frame 15:55:20 INFO - PID 24814 | 15:55:20 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.366193181818193 ms/frame 15:55:20 INFO - PID 24814 | 15:55:20 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.932814207650283 ms/frame 15:55:20 INFO - PID 24814 | 15:55:20 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.713029661016956 ms/frame 15:55:20 INFO - PID 24814 | 15:55:20 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.976646706586818 ms/frame 15:55:20 INFO - PID 24814 | 15:55:20 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.36486742424244 ms/frame 15:55:20 INFO - PID 24814 | 15:55:20 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.81675675675675 ms/frame 15:55:20 INFO - PID 24814 | 15:55:20 INFO - PID 24814 | Cycle 1(10): loaded http://localhost:36758/tests/video/video_playback.html (next: http://localhost:36758/tests/video/video_playback.html) 15:56:06 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6969739819004526 ms/frame 15:56:06 INFO - PID 24814 | 15:56:06 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.670121035058431 ms/frame 15:56:06 INFO - PID 24814 | 15:56:06 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7787492590397154 ms/frame 15:56:06 INFO - PID 24814 | 15:56:06 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7069581911262801 ms/frame 15:56:06 INFO - PID 24814 | 15:56:06 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_2_startup = 4.208169705469847 ms/frame 15:56:06 INFO - PID 24814 | 15:56:06 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.15122406639004 ms/frame 15:56:06 INFO - PID 24814 | 15:56:06 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1_startup = 3.4931082654249104 ms/frame 15:56:06 INFO - PID 24814 | 15:56:06 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4191196581196603 ms/frame 15:56:06 INFO - PID 24814 | 15:56:06 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.736185468451239 ms/frame 15:56:06 INFO - PID 24814 | 15:56:06 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.620702247191015 ms/frame 15:56:06 INFO - PID 24814 | 15:56:06 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_2_startup = 9.904455445544553 ms/frame 15:56:06 INFO - PID 24814 | 15:56:06 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_2_inclip = 9.574090909090913 ms/frame 15:56:06 INFO - PID 24814 | 15:56:06 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.408612167300381 ms/frame 15:56:06 INFO - PID 24814 | 15:56:06 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1_inclip = 11.055745856353612 ms/frame 15:56:06 INFO - PID 24814 | 15:56:06 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.501750000000023 ms/frame 15:56:06 INFO - PID 24814 | 15:56:06 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.979790419161677 ms/frame 15:56:06 INFO - PID 24814 | 15:56:06 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.451812977099237 ms/frame 15:56:06 INFO - PID 24814 | 15:56:06 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.695855614973262 ms/frame 15:56:06 INFO - PID 24814 | 15:56:06 INFO - PID 24814 | Cycle 1(11): loaded http://localhost:36758/tests/video/video_playback.html (next: http://localhost:36758/tests/video/video_playback.html) 15:56:52 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6912852311161215 ms/frame 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.671123642439432 ms/frame 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.8003059388122373 ms/frame 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7849330954504905 ms/frame 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_2_startup = 4.1853765690376585 ms/frame 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.2200949367088585 ms/frame 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1_startup = 3.505771028037386 ms/frame 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3843654822335023 ms/frame 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.769442307692309 ms/frame 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.666090651558066 ms/frame 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_2_startup = 10.033461538461541 ms/frame 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | testsrc.480p.60fps.webm_scale_2_inclip = 9.711771844660195 ms/frame 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.453568702290074 ms/frame 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1_inclip = 11.112222222222247 ms/frame 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.824145299145323 ms/frame 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.274846625766845 ms/frame 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.541576923076914 ms/frame 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.05099447513814 ms/frame 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | Cycle 1(12): loaded http://localhost:36758/tests/video/video_playback.html (next: http://localhost:36758/tests/video/video_playback.html) 15:56:52 INFO - PID 24814 | __start_tp_report 15:56:52 INFO - PID 24814 | _x_x_mozilla_page_load 15:56:52 INFO - PID 24814 | _x_x_mozilla_page_load_details 15:56:52 INFO - PID 24814 | |i|pagename|runs| 15:56:52 INFO - PID 24814 | |0;240p.120fps.mp4_scale_1_startup;1.6865767284991569;1.686424957841484;1.6830818844643858;1.6846715328467154;1.6846069623806852;1.6831043185642176;1.6809467787114847;1.6839730639730641;1.6857050561797755;1.6926931754089114;1.6969739819004526;1.6912852311161215 15:56:52 INFO - PID 24814 | |1;240p.120fps.mp4_scale_1_inclip;1.6700417362270448;1.6694782971619364;1.67426359832636;1.6726463210702347;1.6705425709515855;1.6705300500834726;1.6728971571906353;1.6730267558528429;1.6739037656903761;1.6727717391304349;1.670121035058431;1.671123642439432 15:56:52 INFO - PID 24814 | |2;240p.120fps.mp4_scale_1.1_startup;1.7742519219396808;1.7641093474426808;1.7397536231884057;1.756841334894614;1.766368452030606;1.75992082111437;1.7396347826086955;1.8039927841250758;1.7826411170528815;1.7744736842105264;1.7787492590397154;1.8003059388122373 15:56:52 INFO - PID 24814 | |3;240p.120fps.mp4_scale_1.1_inclip;1.731688311688312;1.7560096575943804;1.7348222029488292;1.716828326180257;1.7747559893522624;1.7908728737690232;1.7454363001745197;1.7707876106194689;1.728686257562663;1.7629339207048453;1.7069581911262801;1.7849330954504905 15:56:52 INFO - PID 24814 | |4;240p.120fps.mp4_scale_2_startup;3.9483684210526295;4.133305785123965;4.167138888888889;3.953498023715415;4.156530470914129;4.027550335570469;4.231882933709448;4.150013831258645;3.9581728232189977;4.184623430962343;4.208169705469847;4.1853765690376585 15:56:52 INFO - PID 24814 | |5;240p.120fps.mp4_scale_2_inclip;4.185355648535565;3.937716535433072;4.229027484143763;3.945552268244577;4.14221532091097;4.151566390041494;4.185826359832637;4.124938144329896;4.212494736842104;4.158232848232846;4.15122406639004;4.2200949367088585 15:56:52 INFO - PID 24814 | |6;480p.60fps.webm_scale_1_startup;3.46019607843137;3.50100933488915;3.705049382716047;3.6686308068459663;3.585179211469532;3.6240760869565203;3.5018961493582283;3.5173329425556856;3.537989386792451;3.5514556213017725;3.4931082654249104;3.505771028037386 15:56:52 INFO - PID 24814 | |7;480p.60fps.webm_scale_1_inclip;3.3334250000000005;3.431097770154371;3.597500000000005;3.547101063829785;3.533701413427563;3.546560283687947;3.4134470989761074;3.4546459412780686;3.5344699646643147;3.4603460207612486;3.4191196581196603;3.3843654822335023 15:56:52 INFO - PID 24814 | |8;480p.60fps.webm_scale_1.1_startup;3.5847132616487443;5.736864244741875;5.860644531250003;5.671947069943288;5.759692898272552;5.7928281853281804;5.536254612546128;5.587085661080073;5.793272200772202;5.66070754716981;5.736185468451239;5.769442307692309 15:56:52 INFO - PID 24814 | |9;480p.60fps.webm_scale_1.1_inclip;3.9766302186878706;5.572144846796661;5.4209078590785875;5.667096317280455;5.451989100817442;5.378172043010753;5.4072432432432445;5.541454293628809;5.589636871508381;5.589483240223463;5.620702247191015;5.666090651558066 15:56:52 INFO - PID 24814 | |10;480p.60fps.webm_scale_2_startup;9.61892628205128;9.742808441558452;10.205357142857142;9.58626198083067;9.804232026143795;10.172016949152551;9.647877813504817;9.67891935483871;9.524079365079363;10.3811937716263;9.904455445544553;10.033461538461541 15:56:52 INFO - PID 24814 | |11;480p.60fps.webm_scale_2_inclip;9.6671497584541;9.712791262135918;9.901881188118795;9.136803652968032;9.713689320388351;9.952064676616905;10.104343434343434;9.904702970297029;10.10654040404041;9.346238317756997;9.574090909090913;9.711771844660195 15:56:52 INFO - PID 24814 | |12;1080p.60fps.mp4_scale_1_startup;11.76482352941176;11.366022727272732;11.321962264150956;11.583494208494194;11.4090494296578;11.4082699619772;11.58534749034749;11.542096153846138;11.409885931558932;11.366193181818193;11.408612167300381;11.453568702290074 15:56:52 INFO - PID 24814 | |13;1080p.60fps.mp4_scale_1_inclip;10.869619565217402;10.933196721311484;10.872907608695641;10.995384615384635;10.871059782608704;10.706711229946517;10.872173913043456;11.0553867403315;10.991895604395612;10.932814207650283;11.055745856353612;11.112222222222247 15:56:52 INFO - PID 24814 | |14;1080p.60fps.mp4_scale_1.1_startup;12.29959016393442;12.60533613445378;12.553430962343082;12.452614107883795;12.397458677685972;12.448879668049793;12.397582644628084;12.714385593220344;12.55589958158993;12.713029661016956;12.501750000000023;12.824145299145323 15:56:52 INFO - PID 24814 | |15;1080p.60fps.mp4_scale_1.1_inclip;11.837810650887596;11.906309523809536;12.051626506024139;11.497471264367844;11.43057142857142;11.98062874251501;11.910833333333358;11.837810650887553;12.128090909090922;11.976646706586818;11.979790419161677;12.274846625766845 15:56:52 INFO - PID 24814 | |16;1080p.60fps.mp4_scale_2_startup;11.409980988593173;11.451927480916027;11.410247148288988;11.953386454183278;11.495421455938699;11.407718631178719;11.630658914728679;11.321867924528295;11.453778625954197;11.36486742424244;11.451812977099237;11.541576923076914 15:56:52 INFO - PID 24814 | |17;1080p.60fps.mp4_scale_2_inclip;10.93322404371584;11.115972222222222;11.055303867403286;11.176899441340787;10.815405405405398;10.934644808743174;11.116638888888904;10.815054054054073;10.813486486486461;10.81675675675675;10.695855614973262;11.05099447513814 15:56:52 INFO - PID 24814 | __end_tp_report 15:56:52 INFO - PID 24814 | __start_cc_report 15:56:52 INFO - PID 24814 | _x_x_mozilla_cycle_collect,604 15:56:52 INFO - PID 24814 | __end_cc_report 15:56:52 INFO - PID 24814 | __startTimestamp1509317812536__endTimestamp 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | ------- Summary: start ------- 15:56:52 INFO - PID 24814 | Number of tests: 18 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | [#0] 240p.120fps.mp4_scale_1_startup Cycles:12 Average:1.69 Median:1.69 stddev:0.00 (0.3%) stddev-sans-first:0.00 15:56:52 INFO - PID 24814 | Values: 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | [#1] 240p.120fps.mp4_scale_1_inclip Cycles:12 Average:1.67 Median:1.67 stddev:0.00 (0.1%) stddev-sans-first:0.00 15:56:52 INFO - PID 24814 | Values: 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | [#2] 240p.120fps.mp4_scale_1.1_startup Cycles:12 Average:1.77 Median:1.77 stddev:0.02 (1.1%) stddev-sans-first:0.02 15:56:52 INFO - PID 24814 | Values: 1.8 1.8 1.7 1.8 1.8 1.8 1.7 1.8 1.8 1.8 1.8 1.8 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | [#3] 240p.120fps.mp4_scale_1.1_inclip Cycles:12 Average:1.75 Median:1.76 stddev:0.03 (1.5%) stddev-sans-first:0.03 15:56:52 INFO - PID 24814 | Values: 1.7 1.8 1.7 1.7 1.8 1.8 1.7 1.8 1.7 1.8 1.7 1.8 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | [#4] 240p.120fps.mp4_scale_2_startup Cycles:12 Average:4.11 Median:4.16 stddev:0.11 (2.5%) stddev-sans-first:0.10 15:56:52 INFO - PID 24814 | Values: 3.9 4.1 4.2 4.0 4.2 4.0 4.2 4.2 4.0 4.2 4.2 4.2 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | [#5] 240p.120fps.mp4_scale_2_inclip Cycles:12 Average:4.14 Median:4.17 stddev:0.10 (2.3%) stddev-sans-first:0.10 15:56:52 INFO - PID 24814 | Values: 4.2 3.9 4.2 3.9 4.1 4.2 4.2 4.1 4.2 4.2 4.2 4.2 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | [#6] 480p.60fps.webm_scale_1_startup Cycles:12 Average:3.55 Median:3.54 stddev:0.08 (2.1%) stddev-sans-first:0.07 15:56:52 INFO - PID 24814 | Values: 3.5 3.5 3.7 3.7 3.6 3.6 3.5 3.5 3.5 3.6 3.5 3.5 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | [#7] 480p.60fps.webm_scale_1_inclip Cycles:12 Average:3.47 Median:3.50 stddev:0.08 (2.3%) stddev-sans-first:0.07 15:56:52 INFO - PID 24814 | Values: 3.3 3.4 3.6 3.5 3.5 3.5 3.4 3.5 3.5 3.5 3.4 3.4 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | [#8] 480p.60fps.webm_scale_1.1_startup Cycles:12 Average:5.54 Median:5.75 stddev:0.62 (10.8%) stddev-sans-first:0.10 15:56:52 INFO - PID 24814 | Values: 3.6 5.7 5.9 5.7 5.8 5.8 5.5 5.6 5.8 5.7 5.7 5.8 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | [#9] 480p.60fps.webm_scale_1.1_inclip Cycles:12 Average:5.41 Median:5.58 stddev:0.46 (8.3%) stddev-sans-first:0.10 15:56:52 INFO - PID 24814 | Values: 4.0 5.6 5.4 5.7 5.5 5.4 5.4 5.5 5.6 5.6 5.6 5.7 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | [#10] 480p.60fps.webm_scale_2_startup Cycles:12 Average:9.86 Median:9.63 stddev:0.28 (2.9%) stddev-sans-first:0.28 15:56:52 INFO - PID 24814 | Values: 9.6 9.7 10.2 9.6 9.8 10.2 9.6 9.7 9.5 10.4 9.9 10.0 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | [#11] 480p.60fps.webm_scale_2_inclip Cycles:12 Average:9.74 Median:9.71 stddev:0.29 (3.0%) stddev-sans-first:0.30 15:56:52 INFO - PID 24814 | Values: 9.7 9.7 9.9 9.1 9.7 10.0 10.1 9.9 10.1 9.3 9.6 9.7 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | [#12] 1080p.60fps.mp4_scale_1_startup Cycles:12 Average:11.47 Median:11.43 stddev:0.13 (1.1%) stddev-sans-first:0.09 15:56:52 INFO - PID 24814 | Values: 11.8 11.4 11.3 11.6 11.4 11.4 11.6 11.5 11.4 11.4 11.4 11.5 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | [#13] 1080p.60fps.mp4_scale_1_inclip Cycles:12 Average:10.94 Median:10.96 stddev:0.11 (1.0%) stddev-sans-first:0.11 15:56:52 INFO - PID 24814 | Values: 10.9 10.9 10.9 11.0 10.9 10.7 10.9 11.1 11.0 10.9 11.1 11.1 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | [#14] 1080p.60fps.mp4_scale_1.1_startup Cycles:12 Average:12.54 Median:12.55 stddev:0.15 (1.2%) stddev-sans-first:0.14 15:56:52 INFO - PID 24814 | Values: 12.3 12.6 12.6 12.5 12.4 12.4 12.4 12.7 12.6 12.7 12.5 12.8 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | [#15] 1080p.60fps.mp4_scale_1.1_inclip Cycles:12 Average:11.90 Median:11.98 stddev:0.24 (2.0%) stddev-sans-first:0.25 15:56:52 INFO - PID 24814 | Values: 11.8 11.9 12.1 11.5 11.4 12.0 11.9 11.8 12.1 12.0 12.0 12.3 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | [#16] 1080p.60fps.mp4_scale_2_startup Cycles:12 Average:11.49 Median:11.45 stddev:0.17 (1.5%) stddev-sans-first:0.17 15:56:52 INFO - PID 24814 | Values: 11.4 11.5 11.4 12.0 11.5 11.4 11.6 11.3 11.5 11.4 11.5 11.5 15:56:52 INFO - PID 24814 | 15:56:52 INFO - PID 24814 | [#17] 1080p.60fps.mp4_scale_2_inclip Cycles:12 Average:10.95 Median:10.99 stddev:0.16 (1.4%) stddev-sans-first:0.16 15:56:52 INFO - PID 24814 | Values: 10.9 11.1 11.1 11.2 10.8 10.9 11.1 10.8 10.8 10.8 10.7 11.1 15:56:52 INFO - PID 24814 | -------- Summary: end -------- 15:56:52 INFO - PID 24814 | 15:56:53 INFO - TEST-INFO | 24814: exit 0 15:56:53 INFO - TEST-OK | basic_compositor_video | took 562458ms 15:56:53 INFO - TEST-START | glvideo 15:56:53 INFO - Initialising browser for glvideo test... 15:56:53 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:36758/getInfo.html -profile /tmp/tmpGN6Q16/profile 15:56:53 INFO - TEST-INFO | started process 26102 (/builds/slave/test/build/application/firefox/firefox http://localhost:36758/getInfo.html) 15:57:00 INFO - TEST-INFO | 26102: exit 0 15:57:00 INFO - Browser initialized. 15:57:00 INFO - Running cycle 1/1 for glvideo test... 15:57:00 INFO - Using env: {'DISPLAY': ':0', 15:57:00 INFO - 'HOME': '/home/cltbld', 15:57:00 INFO - 'JSGC_DISABLE_POISONING': '1', 15:57:00 INFO - 'LANG': 'en_US.UTF-8', 15:57:00 INFO - 'LANGUAGE': 'en_US:en', 15:57:00 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 15:57:00 INFO - 'LOGNAME': 'cltbld', 15:57:00 INFO - 'MAIL': '/var/mail/cltbld', 15:57:00 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 15:57:00 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 15:57:00 INFO - 'MOZ_CRASHREPORTER': '1', 15:57:00 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 15:57:00 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 15:57:00 INFO - 'MOZ_NO_REMOTE': '1', 15:57:00 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 15:57:00 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 15:57:00 INFO - 'NO_EM_RESTART': '1', 15:57:00 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 15:57:00 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 15:57:00 INFO - 'PWD': '/builds/slave/test', 15:57:00 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 15:57:00 INFO - 'RUST_BACKTRACE': 'full', 15:57:00 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 15:57:00 INFO - 'SHELL': '/bin/bash', 15:57:00 INFO - 'SHLVL': '1', 15:57:00 INFO - 'TERM': 'linux', 15:57:00 INFO - 'TMOUT': '86400', 15:57:00 INFO - 'USER': 'cltbld', 15:57:00 INFO - 'XDG_SESSION_COOKIE': '8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451', 15:57:00 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 15:57:00 INFO - '_': '/tools/buildbot/bin/python'} 15:57:00 INFO - TEST-INFO | started process 26337 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpGN6Q16/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/webgl/glvideo.manifest.develop -tpnoisy -tploadnocache -tpcycles 1 -tppagecycles 5) 15:57:01 INFO - PID 26337 | 15:57:01 INFO - PID 26337 | (/builds/slave/test/build/application/firefox/firefox:26389): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 15:57:01 INFO - PID 26337 | 15:57:02 INFO - PID 26337 | [talos glvideo result] Mean tick time across 100 ticks: 6.73705 ms 15:57:02 INFO - PID 26337 | Cycle 1(1): loaded http://localhost:36758/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:36758/tests/webgl/benchmarks/video/video_upload.html) 15:57:04 INFO - PID 26337 | [talos glvideo result] Mean tick time across 100 ticks: 6.5013 ms 15:57:04 INFO - PID 26337 | Cycle 1(2): loaded http://localhost:36758/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:36758/tests/webgl/benchmarks/video/video_upload.html) 15:57:05 INFO - PID 26337 | [talos glvideo result] Mean tick time across 100 ticks: 6.64295 ms 15:57:05 INFO - PID 26337 | Cycle 1(3): loaded http://localhost:36758/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:36758/tests/webgl/benchmarks/video/video_upload.html) 15:57:06 INFO - PID 26337 | [talos glvideo result] Mean tick time across 100 ticks: 6.639100000000001 ms 15:57:06 INFO - PID 26337 | Cycle 1(4): loaded http://localhost:36758/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:36758/tests/webgl/benchmarks/video/video_upload.html) 15:57:08 INFO - PID 26337 | [talos glvideo result] Mean tick time across 100 ticks: 6.60245 ms 15:57:08 INFO - PID 26337 | Cycle 1(5): loaded http://localhost:36758/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:36758/tests/webgl/benchmarks/video/video_upload.html) 15:57:08 INFO - PID 26337 | __start_tp_report 15:57:08 INFO - PID 26337 | _x_x_mozilla_page_load 15:57:08 INFO - PID 26337 | _x_x_mozilla_page_load_details 15:57:08 INFO - PID 26337 | |i|pagename|runs| 15:57:08 INFO - PID 26337 | |0;Mean tick time across 100 ticks: ;6.73705;6.5013;6.64295;6.639100000000001;6.60245 15:57:08 INFO - PID 26337 | __end_tp_report 15:57:08 INFO - PID 26337 | __start_cc_report 15:57:08 INFO - PID 26337 | _x_x_mozilla_cycle_collect,283 15:57:08 INFO - PID 26337 | __end_cc_report 15:57:08 INFO - PID 26337 | __startTimestamp1509317828420__endTimestamp 15:57:08 INFO - PID 26337 | 15:57:08 INFO - PID 26337 | ------- Summary: start ------- 15:57:08 INFO - PID 26337 | Number of tests: 1 15:57:08 INFO - PID 26337 | 15:57:08 INFO - PID 26337 | [#0] Mean tick time across 100 ticks: Cycles:5 Average:6.62 Median:6.64 stddev:0.08 (1.3%) stddev-sans-first:0.07 15:57:08 INFO - PID 26337 | Values: 6.7 6.5 6.6 6.6 6.6 15:57:08 INFO - PID 26337 | -------- Summary: end -------- 15:57:08 INFO - PID 26337 | 15:57:08 INFO - PID 26337 | *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping 15:57:09 INFO - TEST-INFO | 26337: exit 0 15:57:09 INFO - TEST-OK | glvideo | took 15982ms 15:57:09 INFO - SUITE-END | took 578s 15:57:09 INFO - Completed test suite (00:09:38) 15:57:09 INFO - PERFHERDER_DATA: {"framework": {"name": "talos"}, "suites": [{"extraOptions": ["e10s"], "name": "basic_compositor_video", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 5.612010245738726, "subtests": [{"name": "240p.120fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.6865767284991569, 1.686424957841484, 1.6830818844643858, 1.6846715328467154, 1.6846069623806852, 1.6831043185642176, 1.6809467787114847, 1.6839730639730641, 1.6857050561797755, 1.6926931754089114, 1.6969739819004526, 1.6912852311161215], "value": 1.6846715328467154, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.6700417362270448, 1.6694782971619364, 1.67426359832636, 1.6726463210702347, 1.6705425709515855, 1.6705300500834726, 1.6728971571906353, 1.6730267558528429, 1.6739037656903761, 1.6727717391304349, 1.670121035058431, 1.671123642439432], "value": 1.6726463210702347, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.7742519219396808, 1.7641093474426808, 1.7397536231884057, 1.756841334894614, 1.766368452030606, 1.75992082111437, 1.7396347826086955, 1.8039927841250758, 1.7826411170528815, 1.7744736842105264, 1.7787492590397154, 1.8003059388122373], "value": 1.766368452030606, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.731688311688312, 1.7560096575943804, 1.7348222029488292, 1.716828326180257, 1.7747559893522624, 1.7908728737690232, 1.7454363001745197, 1.7707876106194689, 1.728686257562663, 1.7629339207048453, 1.7069581911262801, 1.7849330954504905], "value": 1.7560096575943804, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.9483684210526295, 4.133305785123965, 4.167138888888889, 3.953498023715415, 4.156530470914129, 4.027550335570469, 4.231882933709448, 4.150013831258645, 3.9581728232189977, 4.184623430962343, 4.208169705469847, 4.1853765690376585], "value": 4.156530470914129, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.185355648535565, 3.937716535433072, 4.229027484143763, 3.945552268244577, 4.14221532091097, 4.151566390041494, 4.185826359832637, 4.124938144329896, 4.212494736842104, 4.158232848232846, 4.15122406639004, 4.2200949367088585], "value": 4.151566390041494, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.46019607843137, 3.50100933488915, 3.705049382716047, 3.6686308068459663, 3.585179211469532, 3.6240760869565203, 3.5018961493582283, 3.5173329425556856, 3.537989386792451, 3.5514556213017725, 3.4931082654249104, 3.505771028037386], "value": 3.537989386792451, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.3334250000000005, 3.431097770154371, 3.597500000000005, 3.547101063829785, 3.533701413427563, 3.546560283687947, 3.4134470989761074, 3.4546459412780686, 3.5344699646643147, 3.4603460207612486, 3.4191196581196603, 3.3843654822335023], "value": 3.4603460207612486, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.5847132616487443, 5.736864244741875, 5.860644531250003, 5.671947069943288, 5.759692898272552, 5.7928281853281804, 5.536254612546128, 5.587085661080073, 5.793272200772202, 5.66070754716981, 5.736185468451239, 5.769442307692309], "value": 5.736864244741875, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.9766302186878706, 5.572144846796661, 5.4209078590785875, 5.667096317280455, 5.451989100817442, 5.378172043010753, 5.4072432432432445, 5.541454293628809, 5.589636871508381, 5.589483240223463, 5.620702247191015, 5.666090651558066], "value": 5.572144846796661, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [9.61892628205128, 9.742808441558452, 10.205357142857142, 9.58626198083067, 9.804232026143795, 10.172016949152551, 9.647877813504817, 9.67891935483871, 9.524079365079363, 10.3811937716263, 9.904455445544553, 10.033461538461541], "value": 9.804232026143795, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [9.6671497584541, 9.712791262135918, 9.901881188118795, 9.136803652968032, 9.713689320388351, 9.952064676616905, 10.104343434343434, 9.904702970297029, 10.10654040404041, 9.346238317756997, 9.574090909090913, 9.711771844660195], "value": 9.713689320388351, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.76482352941176, 11.366022727272732, 11.321962264150956, 11.583494208494194, 11.4090494296578, 11.4082699619772, 11.58534749034749, 11.542096153846138, 11.409885931558932, 11.366193181818193, 11.408612167300381, 11.453568702290074], "value": 11.4090494296578, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.869619565217402, 10.933196721311484, 10.872907608695641, 10.995384615384635, 10.871059782608704, 10.706711229946517, 10.872173913043456, 11.0553867403315, 10.991895604395612, 10.932814207650283, 11.055745856353612, 11.112222222222247], "value": 10.933196721311484, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [12.29959016393442, 12.60533613445378, 12.553430962343082, 12.452614107883795, 12.397458677685972, 12.448879668049793, 12.397582644628084, 12.714385593220344, 12.55589958158993, 12.713029661016956, 12.501750000000023, 12.824145299145323], "value": 12.553430962343082, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.837810650887596, 11.906309523809536, 12.051626506024139, 11.497471264367844, 11.43057142857142, 11.98062874251501, 11.910833333333358, 11.837810650887553, 12.128090909090922, 11.976646706586818, 11.979790419161677, 12.274846625766845], "value": 11.976646706586818, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.409980988593173, 11.451927480916027, 11.410247148288988, 11.953386454183278, 11.495421455938699, 11.407718631178719, 11.630658914728679, 11.321867924528295, 11.453778625954197, 11.36486742424244, 11.451812977099237, 11.541576923076914], "value": 11.451927480916027, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.93322404371584, 11.115972222222222, 11.055303867403286, 11.176899441340787, 10.815405405405398, 10.934644808743174, 11.116638888888904, 10.815054054054073, 10.813486486486461, 10.81675675675675, 10.695855614973262, 11.05099447513814], "value": 10.934644808743174, "unit": "ms/frame"}]}, {"lowerIsBetter": true, "subtests": [{"name": "Mean tick time across 100 ticks: ", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [6.73705, 6.5013, 6.64295, 6.639100000000001, 6.60245], "value": 6.620775, "unit": "ms"}], "extraOptions": ["e10s"], "name": "glvideo", "alertThreshold": 2.0}]} 15:57:09 INFO - Return code: 0 15:57:09 INFO - Validating PERFHERDER_DATA against /builds/slave/test/scripts/external_tools/performance-artifact-schema.json 15:57:09 INFO - # TBPL SUCCESS # 15:57:09 INFO - Running post-action listener: _package_coverage_data 15:57:09 INFO - Running post-action listener: _resource_record_post_action 15:57:09 INFO - [mozharness: 2017-10-29 22:57:09.550325Z] Finished run-tests step (success) 15:57:09 INFO - Running post-run listener: _resource_record_post_run 15:57:09 INFO - Total resource usage - Wall time: 598s; CPU: 39.0%; Read bytes: 12288; Write bytes: 316547072; Read time: 368; Write time: 1004184 15:57:09 INFO - TinderboxPrint: CPU usage
38.8% 15:57:09 INFO - TinderboxPrint: I/O read bytes / time
12,288 / 368 15:57:09 INFO - TinderboxPrint: I/O write bytes / time
316,547,072 / 1,004,184 15:57:09 INFO - TinderboxPrint: CPU idle
2,867.9 (61.2%) 15:57:09 INFO - TinderboxPrint: CPU system
302.9 (6.5%) 15:57:09 INFO - TinderboxPrint: CPU user
1,493.5 (31.8%) 15:57:09 INFO - TinderboxPrint: Swap in / out
0 / 0 15:57:09 INFO - install - Wall time: 19s; CPU: 13.0%; Read bytes: 0; Write bytes: 3682304; Read time: 0; Write time: 2152 15:57:09 INFO - setup-mitmproxy - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0 15:57:09 INFO - run-tests - Wall time: 579s; CPU: 40.0%; Read bytes: 12288; Write bytes: 309628928; Read time: 368; Write time: 1000628 15:57:09 INFO - Running post-run listener: _upload_blobber_files 15:57:09 INFO - Blob upload gear active. 15:57:09 INFO - Preparing to upload files from /builds/slave/test/build/blobber_upload_dir. 15:57:09 INFO - Files from /builds/slave/test/build/blobber_upload_dir are to be uploaded with branch at the following location(s): https://blobupload.elasticbeanstalk.com 15:57:09 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/venv/bin/blobberc.py', '-u', 'https://blobupload.elasticbeanstalk.com', '-a', '/builds/slave/test/oauth.txt', '-b', 'Firefox-Non-PGO', '-d', '/builds/slave/test/build/blobber_upload_dir', '--output-manifest', '/builds/slave/test/build/uploaded_files.json'] 15:57:09 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/venv/bin/blobberc.py -u https://blobupload.elasticbeanstalk.com -a /builds/slave/test/oauth.txt -b Firefox-Non-PGO -d /builds/slave/test/build/blobber_upload_dir --output-manifest /builds/slave/test/build/uploaded_files.json 15:57:10 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:334: SNIMissingWarning: An HTTPS request has been made, but the SNI (Subject Name Indication) extension to TLS is not available on this platform. This may cause the server to present an incorrect TLS certificate, which can cause validation failures. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 15:57:10 INFO - SNIMissingWarning 15:57:10 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 15:57:10 INFO - InsecurePlatformWarning 15:57:10 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/requests/packages/urllib3/connection.py:340: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.) 15:57:10 INFO - SubjectAltNameWarning 15:57:10 INFO - (blobuploader) - INFO - Open directory for files ... 15:57:10 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-e10s_raw.log ... 15:57:10 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 15:57:10 INFO - (blobuploader) - INFO - Uploading, attempt #1. 15:57:10 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 15:57:10 INFO - InsecurePlatformWarning 15:57:10 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/requests/packages/urllib3/connection.py:340: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.) 15:57:10 INFO - SubjectAltNameWarning 15:57:10 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 15:57:10 INFO - InsecurePlatformWarning 15:57:11 INFO - (blobuploader) - INFO - TinderboxPrint: g4-e10s_raw.log: uploaded 15:57:11 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 15:57:11 INFO - (blobuploader) - INFO - Done attempting. 15:57:11 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/resource-usage.json ... 15:57:11 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 15:57:11 INFO - (blobuploader) - INFO - Uploading, attempt #1. 15:57:11 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 15:57:11 INFO - InsecurePlatformWarning 15:57:11 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/requests/packages/urllib3/connection.py:340: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.) 15:57:11 INFO - SubjectAltNameWarning 15:57:16 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 15:57:16 INFO - InsecurePlatformWarning 15:57:16 INFO - (blobuploader) - INFO - TinderboxPrint: resource-usage.json: uploaded 15:57:16 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 15:57:16 INFO - (blobuploader) - INFO - Done attempting. 15:57:16 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-e10s_errorsummary.log ... 15:57:16 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 15:57:16 INFO - (blobuploader) - INFO - Uploading, attempt #1. 15:57:16 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 15:57:16 INFO - InsecurePlatformWarning 15:57:16 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/requests/packages/urllib3/connection.py:340: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.) 15:57:16 INFO - SubjectAltNameWarning 15:57:17 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 15:57:17 INFO - InsecurePlatformWarning 15:57:17 INFO - (blobuploader) - INFO - TinderboxPrint: g4-e10s_errorsummary.log: uploaded 15:57:17 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 15:57:17 INFO - (blobuploader) - INFO - Done attempting. 15:57:17 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/perfherder-data.json ... 15:57:17 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 15:57:17 INFO - (blobuploader) - INFO - Uploading, attempt #1. 15:57:17 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 15:57:17 INFO - InsecurePlatformWarning 15:57:17 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/requests/packages/urllib3/connection.py:340: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.) 15:57:17 INFO - SubjectAltNameWarning 15:57:18 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 15:57:18 INFO - InsecurePlatformWarning 15:57:18 INFO - (blobuploader) - INFO - TinderboxPrint: perfherder-data.json: uploaded 15:57:18 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 15:57:18 INFO - (blobuploader) - INFO - Done attempting. 15:57:18 INFO - (blobuploader) - INFO - Iteration through files over. 15:57:18 INFO - Return code: 0 15:57:18 INFO - rmtree: /builds/slave/test/build/uploaded_files.json 15:57:18 INFO - retry: Calling remove with args: ('/builds/slave/test/build/uploaded_files.json',), kwargs: {}, attempt #1 15:57:18 INFO - Setting buildbot property blobber_files to {"g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/c8f388b4d9f1269d87ce24de47f34e451cf544fa216e440b0a3873b876b4dacbb25326451232a467cd420dd70b9e8e14d7a6e16cc620b3e6378de77778b2a08d", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/97b3d2af116f0057e52c22de521128bb39175510cc87e090415512f77353a130a91841752fbaa272a42f2e3916733b2a3222e23547881c80d5cd72bd49b1df19", "perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/0d31a80ff48d54c2950a1b8468064116bf278a002018cb51d891090a09b21c871f88dccb6c6b5740af55c17a9812dcf53424750d0a12483fa4ff8b4bb5967586", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/85dd6ca426dea11d3f10304be285bf57fecd47bd2ec865f4b32f2ed2fc44e952209041b26816fea4ad4a87a9a769e7e2705bfec8a883c0222e4fa70897db24ff"} 15:57:18 INFO - Writing buildbot properties ['blobber_files'] to /builds/slave/test/properties/blobber_files 15:57:18 INFO - Writing to file /builds/slave/test/properties/blobber_files 15:57:18 INFO - Contents: 15:57:18 INFO - blobber_files:{"g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/c8f388b4d9f1269d87ce24de47f34e451cf544fa216e440b0a3873b876b4dacbb25326451232a467cd420dd70b9e8e14d7a6e16cc620b3e6378de77778b2a08d", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/97b3d2af116f0057e52c22de521128bb39175510cc87e090415512f77353a130a91841752fbaa272a42f2e3916733b2a3222e23547881c80d5cd72bd49b1df19", "perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/0d31a80ff48d54c2950a1b8468064116bf278a002018cb51d891090a09b21c871f88dccb6c6b5740af55c17a9812dcf53424750d0a12483fa4ff8b4bb5967586", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/85dd6ca426dea11d3f10304be285bf57fecd47bd2ec865f4b32f2ed2fc44e952209041b26816fea4ad4a87a9a769e7e2705bfec8a883c0222e4fa70897db24ff"} 15:57:18 INFO - Running post-run listener: copy_logs_to_upload_dir 15:57:18 INFO - Copying logs to upload dir... 15:57:18 INFO - mkdir: /builds/slave/test/build/upload/logs 15:57:18 INFO - Copying logs to upload dir... program finished with exit code 0 elapsedTime=696.717399 ========= master_lag: 0.04 ========= ========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 11 mins, 36 secs) (at 2017-10-29 15:57:18.419077) ========= ========= Started set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-10-29 15:57:18.422957) ========= bash -c 'for file in `ls -1`; do cat $file; done' in dir /builds/slave/test/properties (timeout 1200 secs) watching logfiles {} argv: ['bash', '-c', 'for file in `ls -1`; do cat $file; done'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PWD=/builds/slave/test/properties SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False blobber_files:{"g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/c8f388b4d9f1269d87ce24de47f34e451cf544fa216e440b0a3873b876b4dacbb25326451232a467cd420dd70b9e8e14d7a6e16cc620b3e6378de77778b2a08d", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/97b3d2af116f0057e52c22de521128bb39175510cc87e090415512f77353a130a91841752fbaa272a42f2e3916733b2a3222e23547881c80d5cd72bd49b1df19", "perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/0d31a80ff48d54c2950a1b8468064116bf278a002018cb51d891090a09b21c871f88dccb6c6b5740af55c17a9812dcf53424750d0a12483fa4ff8b4bb5967586", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/85dd6ca426dea11d3f10304be285bf57fecd47bd2ec865f4b32f2ed2fc44e952209041b26816fea4ad4a87a9a769e7e2705bfec8a883c0222e4fa70897db24ff"} build_url:https://queue.taskcluster.net/v1/task/QMTqhJs6Rr-6xXFHz6mTCQ/artifacts/public/build/target.tar.bz2 program finished with exit code 0 elapsedTime=0.011501 build_url: 'https://queue.taskcluster.net/v1/task/QMTqhJs6Rr-6xXFHz6mTCQ/artifacts/public/build/target.tar.bz2' blobber_files: '{"g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/c8f388b4d9f1269d87ce24de47f34e451cf544fa216e440b0a3873b876b4dacbb25326451232a467cd420dd70b9e8e14d7a6e16cc620b3e6378de77778b2a08d", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/97b3d2af116f0057e52c22de521128bb39175510cc87e090415512f77353a130a91841752fbaa272a42f2e3916733b2a3222e23547881c80d5cd72bd49b1df19", "perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/0d31a80ff48d54c2950a1b8468064116bf278a002018cb51d891090a09b21c871f88dccb6c6b5740af55c17a9812dcf53424750d0a12483fa4ff8b4bb5967586", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/85dd6ca426dea11d3f10304be285bf57fecd47bd2ec865f4b32f2ed2fc44e952209041b26816fea4ad4a87a9a769e7e2705bfec8a883c0222e4fa70897db24ff"}' ========= master_lag: 0.02 ========= ========= Finished set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-10-29 15:57:18.453803) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-10-29 15:57:18.454143) ========= rm -f oauth.txt in dir /builds/slave/test/. (timeout 1200 secs) watching logfiles {} argv: ['rm', '-f', 'oauth.txt'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PWD=/builds/slave/test SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=8783db0840cc980e80bb0bd400000236-1509316951.70478-1014641451 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.004594 ========= master_lag: 0.08 ========= ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-10-29 15:57:18.541190) ========= ========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2017-10-29 15:57:18.541635) ========= ========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2017-10-29 15:57:18.542070) ========= ========= Total master_lag: 0.24 =========