builder: mozilla-central_ubuntu64_hw_qr_test-g4-e10s slave: talos-linux64-ix-021 starttime: 1508755262.9 results: success (0) revision: d49501f258b105c5e2dcd0a59896ec1ceabf726b ========= Started set props: master (results: 0, elapsed: 0 secs) (at 2017-10-23 03:41:02.901517) ========= master: http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/ ========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2017-10-23 03:41:02.901914) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-10-23 03:41:02.902198) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-10-23 03:41:02.920732) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-10-23 03:41:02.921025) ========= 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=df17445c3590ff7897617a0e00000225-1508755261.676070-755970385 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False --2017-10-23 03:41:02-- 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% 23.7M=0s 2017-10-23 03:41:03 (23.7 MB/s) - `archiver_client.py' saved [12179/12179] program finished with exit code 0 elapsedTime=0.136593 ========= master_lag: 0.02 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-10-23 03:41:03.074506) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-10-23 03:41:03.074812) ========= 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=df17445c3590ff7897617a0e00000225-1508755261.676070-755970385 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.021120 ========= master_lag: 0.03 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-10-23 03:41:03.130401) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 2 secs) (at 2017-10-23 03:41:03.130760) ========= bash -c 'python archiver_client.py mozharness --repo mozilla-central --rev d49501f258b105c5e2dcd0a59896ec1ceabf726b --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 d49501f258b105c5e2dcd0a59896ec1ceabf726b --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=df17445c3590ff7897617a0e00000225-1508755261.676070-755970385 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 2017-10-23 03:41:03,180 truncating revision to first 12 chars 2017-10-23 03:41:03,180 Setting DEBUG logging. 2017-10-23 03:41:03,180 attempt 1/10 2017-10-23 03:41:03,180 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/mozilla-central/d49501f258b1?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness 2017-10-23 03:41:04,703 unpacking tar archive at: mozilla-central-d49501f258b1/testing/mozharness/ program finished with exit code 0 elapsedTime=2.196081 ========= master_lag: 0.02 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 2 secs) (at 2017-10-23 03:41:05.348426) ========= ========= Started set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-10-23 03:41:05.349350) ========= script_repo_revision: d49501f258b105c5e2dcd0a59896ec1ceabf726b ========= Finished set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-10-23 03:41:05.350137) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-10-23 03:41:05.350755) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-10-23 03:41:05.365224) ========= ========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 10 mins, 57 secs) (at 2017-10-23 03:41:05.365890) ========= /tools/buildbot/bin/python scripts/scripts/talos_script.py --suite g4-e10s --add-option --webServer,localhost --branch-name Firefox --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Firefox 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', '--cfg', 'talos/linux_config.py', '--download-symbols', 'ondemand', '--use-talos-json', '--blob-upload-branch', 'Firefox'] 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=df17445c3590ff7897617a0e00000225-1508755261.676070-755970385 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 03:41:05 INFO - MultiFileLogger online at 20171023 03:41:05 in /builds/slave/test 03:41:05 INFO - Run as scripts/scripts/talos_script.py --suite g4-e10s --add-option --webServer,localhost --branch-name Firefox --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Firefox 03:41:05 INFO - Dumping config to /builds/slave/test/logs/localconfig.json. 03:41:05 INFO - {'append_to_log': False, 03:41:05 INFO - 'base_work_dir': '/builds/slave/test', 03:41:05 INFO - 'blob_upload_branch': 'Firefox', 03:41:05 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt', 03:41:05 INFO - 'branch': 'Firefox', 03:41:05 INFO - 'buildbot_json_path': 'buildprops.json', 03:41:05 INFO - 'code_coverage': False, 03:41:05 INFO - 'config_files': ('talos/linux_config.py',), 03:41:05 INFO - 'default_actions': ('clobber', 03:41:05 INFO - 'read-buildbot-config', 03:41:05 INFO - 'download-and-extract', 03:41:05 INFO - 'populate-webroot', 03:41:05 INFO - 'create-virtualenv', 03:41:05 INFO - 'install', 03:41:05 INFO - 'setup-mitmproxy', 03:41:05 INFO - 'run-tests'), 03:41:05 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 03:41:05 INFO - 'disable_ccov_upload': False, 03:41:05 INFO - 'disable_stylo': False, 03:41:05 INFO - 'download_minidump_stackwalk': True, 03:41:05 INFO - 'download_symbols': 'ondemand', 03:41:05 INFO - 'enable_stylo': False, 03:41:05 INFO - 'enable_webrender': False, 03:41:05 INFO - 'exes': {'tooltool.py': '/tools/tooltool.py'}, 03:41:05 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 03:41:05 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 03:41:05 INFO - 'gecko_profile': False, 03:41:05 INFO - 'gecko_profile_interval': 0, 03:41:05 INFO - 'installer_path': 'installer.exe', 03:41:05 INFO - 'log_level': 'info', 03:41:05 INFO - 'log_name': 'talos', 03:41:05 INFO - 'log_to_console': True, 03:41:05 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk', 03:41:05 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest', 03:41:05 INFO - 'opt_config_files': (), 03:41:05 INFO - 'pip_index': False, 03:41:05 INFO - 'suite': 'g4-e10s', 03:41:05 INFO - 'system_bits': '32', 03:41:05 INFO - 'talos_extra_options': ('--webServer', 'localhost'), 03:41:05 INFO - 'title': 'talos-linux64-ix-021', 03:41:05 INFO - 'tooltool_cache': '/builds/tooltool_cache', 03:41:05 INFO - 'use_talos_json': True, 03:41:05 INFO - 'verify': 'False', 03:41:05 INFO - 'virtualenv_path': '/builds/slave/test/build/venv', 03:41:05 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 03:41:05 INFO - 'work_dir': 'build'} 03:41:05 INFO - [mozharness: 2017-10-23 10:41:05.554167Z] Running clobber step. 03:41:05 INFO - Running pre-action listener: _resource_record_pre_action 03:41:05 INFO - Running main action method: clobber 03:41:05 INFO - rmtree: /builds/slave/test/build 03:41:05 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1 03:41:07 INFO - Running post-action listener: _resource_record_post_action 03:41:07 INFO - [mozharness: 2017-10-23 10:41:07.154534Z] Finished clobber step (success) 03:41:07 INFO - [mozharness: 2017-10-23 10:41:07.154629Z] Running read-buildbot-config step. 03:41:07 INFO - Running pre-action listener: _resource_record_pre_action 03:41:07 INFO - Running main action method: read_buildbot_config 03:41:07 INFO - Using buildbot properties: 03:41:07 INFO - { 03:41:07 INFO - "project": "", 03:41:07 INFO - "product": "firefox", 03:41:07 INFO - "who": "archaeopteryx@coole-files.de", 03:41:07 INFO - "installer_path": "public/build/target.tar.bz2", 03:41:07 INFO - "builddir": "mozilla-central_ubuntu64_hw_qr_test-g4-e10s", 03:41:07 INFO - "repository": "https://hg.mozilla.org/mozilla-central", 03:41:07 INFO - "buildername": "Ubuntu HW 12.04 x64 qr mozilla-central talos g4-e10s", 03:41:07 INFO - "stage_platform": "linux64-qr", 03:41:07 INFO - "basedir": "/builds/slave/test", 03:41:07 INFO - "buildnumber": 118, 03:41:07 INFO - "platform": "ubuntu64_hw_qr", 03:41:07 INFO - "master": "http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/", 03:41:07 INFO - "slavebuilddir": "test", 03:41:07 INFO - "taskId": "VhNwf7UWTfOsq66M9pj1zw", 03:41:07 INFO - "branch": "mozilla-central", 03:41:07 INFO - "script_repo_revision": "production", 03:41:07 INFO - "revision": "d49501f258b105c5e2dcd0a59896ec1ceabf726b", 03:41:07 INFO - "slavename": "talos-linux64-ix-021", 03:41:07 INFO - "repo_path": "mozilla-central" 03:41:07 INFO - } 03:41:07 INFO - Finding installer, test and symbols from parent task. 03:41:07 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/VhNwf7UWTfOsq66M9pj1zw'}, attempt #1 03:41:07 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/VhNwf7UWTfOsq66M9pj1zw'}, attempt #1 03:41:08 INFO - Task dependencies: IkLgTIrmT-yJ9Iu89kKCDQ 03:41:08 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/IkLgTIrmT-yJ9Iu89kKCDQ'}, attempt #1 03:41:08 INFO - Set installer_url: https://queue.taskcluster.net/v1/task/IkLgTIrmT-yJ9Iu89kKCDQ/artifacts/public/build/target.tar.bz2 03:41:08 INFO - Set test_packages_url: https://queue.taskcluster.net/v1/task/IkLgTIrmT-yJ9Iu89kKCDQ/artifacts/public/build/target.test_packages.json 03:41:08 INFO - Set symbols_url: https://queue.taskcluster.net/v1/task/IkLgTIrmT-yJ9Iu89kKCDQ/artifacts/public/build/target.crashreporter-symbols.zip 03:41:08 INFO - Running post-action listener: _resource_record_post_action 03:41:08 INFO - [mozharness: 2017-10-23 10:41:08.474852Z] Finished read-buildbot-config step (success) 03:41:08 INFO - [mozharness: 2017-10-23 10:41:08.475069Z] Running download-and-extract step. 03:41:08 INFO - Running pre-action listener: _resource_record_pre_action 03:41:08 INFO - Running main action method: download_and_extract 03:41:08 INFO - mkdir: /builds/slave/test/build/tests 03:41:08 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')]} 03:41:08 INFO - trying https://queue.taskcluster.net/v1/task/IkLgTIrmT-yJ9Iu89kKCDQ/artifacts/public/build/target.test_packages.json 03:41:08 INFO - Downloading https://queue.taskcluster.net/v1/task/IkLgTIrmT-yJ9Iu89kKCDQ/artifacts/public/build/target.test_packages.json to /builds/slave/test/build/target.test_packages.json 03:41:08 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/IkLgTIrmT-yJ9Iu89kKCDQ/artifacts/public/build/target.test_packages.json', 'file_name': '/builds/slave/test/build/target.test_packages.json'}, attempt #1 03:41:09 INFO - Downloaded 989 bytes. 03:41:09 INFO - Reading from file /builds/slave/test/build/target.test_packages.json 03:41:09 INFO - Using the following test package requirements: 03:41:09 INFO - {u'awsy': [u'target.common.tests.zip', u'target.awsy.tests.zip'], 03:41:09 INFO - u'common': [u'target.common.tests.zip'], 03:41:09 INFO - u'cppunittest': [u'target.common.tests.zip', u'target.cppunittest.tests.zip'], 03:41:09 INFO - u'gtest': [u'target.common.tests.zip', u'target.gtest.tests.zip'], 03:41:09 INFO - u'jittest': [u'target.common.tests.zip', u'target.jsshell.zip'], 03:41:09 INFO - u'mochitest': [u'target.common.tests.zip', u'target.mochitest.tests.zip'], 03:41:09 INFO - u'mozbase': [u'target.common.tests.zip'], 03:41:09 INFO - u'reftest': [u'target.common.tests.zip', u'target.reftest.tests.zip'], 03:41:09 INFO - u'talos': [u'target.common.tests.zip', u'target.talos.tests.zip'], 03:41:09 INFO - u'web-platform': [u'target.common.tests.zip', 03:41:09 INFO - u'target.web-platform.tests.tar.gz'], 03:41:09 INFO - u'xpcshell': [u'target.common.tests.zip', u'target.xpcshell.tests.zip']} 03:41:09 INFO - Downloading packages: [u'target.common.tests.zip', u'target.talos.tests.zip'] for test suite categories: ['common', 'talos'] 03:41:09 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/IkLgTIrmT-yJ9Iu89kKCDQ/artifacts/public/build/target.common.tests.zip 03:41:09 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/IkLgTIrmT-yJ9Iu89kKCDQ/artifacts/public/build/target.common.tests.zip'}, attempt #1 03:41:09 INFO - Fetch https://queue.taskcluster.net/v1/task/IkLgTIrmT-yJ9Iu89kKCDQ/artifacts/public/build/target.common.tests.zip into memory 03:41:10 INFO - Content-Length response header: 55950323 03:41:10 INFO - Bytes received: 55950323 03:41:21 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/IkLgTIrmT-yJ9Iu89kKCDQ/artifacts/public/build/target.talos.tests.zip 03:41:21 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/IkLgTIrmT-yJ9Iu89kKCDQ/artifacts/public/build/target.talos.tests.zip'}, attempt #1 03:41:21 INFO - Fetch https://queue.taskcluster.net/v1/task/IkLgTIrmT-yJ9Iu89kKCDQ/artifacts/public/build/target.talos.tests.zip into memory 03:41:22 INFO - Content-Length response header: 18737502 03:41:22 INFO - Bytes received: 18737502 03:41:22 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')]} 03:41:22 INFO - trying https://queue.taskcluster.net/v1/task/IkLgTIrmT-yJ9Iu89kKCDQ/artifacts/public/build/target.tar.bz2 03:41:22 INFO - Downloading https://queue.taskcluster.net/v1/task/IkLgTIrmT-yJ9Iu89kKCDQ/artifacts/public/build/target.tar.bz2 to /builds/slave/test/build/target.tar.bz2 03:41:22 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/IkLgTIrmT-yJ9Iu89kKCDQ/artifacts/public/build/target.tar.bz2', 'file_name': '/builds/slave/test/build/target.tar.bz2'}, attempt #1 03:41:23 INFO - Downloaded 62602933 bytes. 03:41:23 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/IkLgTIrmT-yJ9Iu89kKCDQ/artifacts/public/build/target.tar.bz2 03:41:23 INFO - mkdir: /builds/slave/test/properties 03:41:23 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url 03:41:23 INFO - Writing to file /builds/slave/test/properties/build_url 03:41:23 INFO - Contents: 03:41:23 INFO - build_url:https://queue.taskcluster.net/v1/task/IkLgTIrmT-yJ9Iu89kKCDQ/artifacts/public/build/target.tar.bz2 03:41:23 INFO - Running post-action listener: _resource_record_post_action 03:41:23 INFO - Running post-action listener: find_tests_for_verification 03:41:23 INFO - Running post-action listener: set_extra_try_arguments 03:41:23 INFO - [mozharness: 2017-10-23 10:41:23.835957Z] Finished download-and-extract step (success) 03:41:23 INFO - [mozharness: 2017-10-23 10:41:23.836055Z] Running populate-webroot step. 03:41:23 INFO - Running pre-action listener: _resource_record_pre_action 03:41:23 INFO - Running main action method: populate_webroot 03:41:23 INFO - {'suites': {'chromez-e10s': {'tests': ['tresize', 'tcanvasmark']}, 03:41:23 INFO - 'chromez-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 03:41:23 INFO - 'tests': ['tresize', 03:41:23 INFO - 'tcanvasmark']}, 03:41:23 INFO - 'dromaeojs-e10s': {'tests': ['dromaeo_css', 'kraken']}, 03:41:23 INFO - 'dromaeojs-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 03:41:23 INFO - 'tests': ['dromaeo_css', 03:41:23 INFO - 'kraken']}, 03:41:23 INFO - 'g1-e10s': {'pagesets_name': 'tp5n.zip', 03:41:23 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 03:41:23 INFO - 'g1-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 03:41:23 INFO - 'talos_options': ['--disable-stylo'], 03:41:23 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 03:41:23 INFO - 'g2-e10s': {'pagesets_name': 'tp5n.zip', 03:41:23 INFO - 'tests': ['damp', 'tps']}, 03:41:23 INFO - 'g2-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 03:41:23 INFO - 'talos_options': ['--disable-stylo'], 03:41:23 INFO - 'tests': ['damp', 'tps']}, 03:41:23 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']}, 03:41:23 INFO - 'g3-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 03:41:23 INFO - 'tests': ['dromaeo_dom']}, 03:41:23 INFO - 'g4-e10s': {'tests': ['basic_compositor_video', 'glvideo']}, 03:41:23 INFO - 'g4-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 03:41:23 INFO - 'tests': ['basic_compositor_video', 03:41:23 INFO - 'glvideo']}, 03:41:23 INFO - 'g5-e10s': {'pagesets_name': 'tp5n.zip', 03:41:23 INFO - 'tests': ['ts_paint_webext', 'tp5o_webext']}, 03:41:23 INFO - 'g5-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 03:41:23 INFO - 'talos_options': ['--disable-stylo'], 03:41:23 INFO - 'tests': ['ts_paint_webext', 03:41:23 INFO - 'tp5o_webext']}, 03:41:23 INFO - 'h1-e10s': {'tests': ['ts_paint_heavy']}, 03:41:23 INFO - 'h2-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 03:41:23 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 03:41:23 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 03:41:23 INFO - 'talos_options': ['--mitmproxy', 03:41:23 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 03:41:23 INFO - '--firstNonBlankPaint'], 03:41:23 INFO - 'tests': ['tp6_google_heavy', 03:41:23 INFO - 'tp6_youtube_heavy', 03:41:23 INFO - 'tp6_amazon_heavy', 03:41:23 INFO - 'tp6_facebook_heavy']}, 03:41:23 INFO - 'other-e10s': {'tests': ['a11yr', 03:41:23 INFO - 'ts_paint', 03:41:23 INFO - 'tpaint', 03:41:23 INFO - 'sessionrestore', 03:41:23 INFO - 'sessionrestore_many_windows', 03:41:23 INFO - 'sessionrestore_no_auto_restore', 03:41:23 INFO - 'tabpaint', 03:41:23 INFO - 'cpstartup']}, 03:41:23 INFO - 'other-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 03:41:23 INFO - 'tests': ['a11yr', 03:41:23 INFO - 'ts_paint', 03:41:23 INFO - 'tpaint', 03:41:23 INFO - 'sessionrestore', 03:41:23 INFO - 'sessionrestore_many_windows', 03:41:23 INFO - 'sessionrestore_no_auto_restore', 03:41:23 INFO - 'tabpaint', 03:41:23 INFO - 'cpstartup']}, 03:41:23 INFO - 'perf-reftest-e10s': {'tests': ['perf_reftest']}, 03:41:23 INFO - 'perf-reftest-singletons-e10s': {'tests': ['perf_reftest_singletons']}, 03:41:23 INFO - 'perf-reftest-singletons-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 03:41:23 INFO - 'tests': ['perf_reftest_singletons']}, 03:41:23 INFO - 'perf-reftest-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 03:41:23 INFO - 'tests': ['perf_reftest']}, 03:41:23 INFO - 'speedometer-e10s': {'tests': ['speedometer']}, 03:41:23 INFO - 'speedometer-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 03:41:23 INFO - 'tests': ['speedometer']}, 03:41:23 INFO - 'svgr-e10s': {'tests': ['tsvgx', 03:41:23 INFO - 'tsvgr_opacity', 03:41:23 INFO - 'tart', 03:41:23 INFO - 'tscrollx', 03:41:23 INFO - 'tsvg_static']}, 03:41:23 INFO - 'svgr-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 03:41:23 INFO - 'tests': ['tsvgx', 03:41:23 INFO - 'tsvgr_opacity', 03:41:23 INFO - 'tart', 03:41:23 INFO - 'tscrollx', 03:41:23 INFO - 'tsvg_static']}, 03:41:23 INFO - 'tp5o-e10s': {'pagesets_name': 'tp5n.zip', 'tests': ['tp5o']}, 03:41:23 INFO - 'tp5o-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 03:41:23 INFO - 'talos_options': ['--disable-stylo'], 03:41:23 INFO - 'tests': ['tp5o']}, 03:41:23 INFO - 'tp6-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 03:41:23 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 03:41:23 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 03:41:23 INFO - 'talos_options': ['--mitmproxy', 03:41:23 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 03:41:23 INFO - '--firstNonBlankPaint'], 03:41:23 INFO - 'tests': ['tp6_google', 03:41:23 INFO - 'tp6_youtube', 03:41:23 INFO - 'tp6_amazon', 03:41:23 INFO - 'tp6_facebook']}, 03:41:23 INFO - 'tp6-stylo-disabled-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 03:41:23 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 03:41:23 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 03:41:23 INFO - 'talos_options': ['--disable-stylo', 03:41:23 INFO - '--mitmproxy', 03:41:23 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 03:41:23 INFO - '--firstNonBlankPaint'], 03:41:23 INFO - 'tests': ['tp6_google', 03:41:23 INFO - 'tp6_youtube', 03:41:23 INFO - 'tp6_amazon', 03:41:23 INFO - 'tp6_facebook']}, 03:41:23 INFO - 'tp6-stylo-threads-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 03:41:23 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 03:41:23 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 03:41:23 INFO - 'talos_options': ['--stylo-threads=1', 03:41:23 INFO - '--mitmproxy', 03:41:23 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 03:41:23 INFO - '--firstNonBlankPaint'], 03:41:23 INFO - 'tests': ['tp6_google', 03:41:23 INFO - 'tp6_youtube', 03:41:23 INFO - 'tp6_amazon', 03:41:23 INFO - 'tp6_facebook']}, 03:41:23 INFO - 'xperf-e10s': {'pagesets_name': 'tp5n.zip', 03:41:23 INFO - 'talos_options': ['--xperf_path', 03:41:23 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 03:41:23 INFO - 'tests': ['tp5n']}, 03:41:23 INFO - 'xperf-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 03:41:23 INFO - 'talos_options': ['--disable-stylo', 03:41:23 INFO - '--xperf_path', 03:41:23 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 03:41:23 INFO - 'tests': ['tp5n']}}} 03:41:23 INFO - Running post-action listener: _resource_record_post_action 03:41:23 INFO - [mozharness: 2017-10-23 10:41:23.854465Z] Finished populate-webroot step (success) 03:41:23 INFO - [mozharness: 2017-10-23 10:41:23.854554Z] Running create-virtualenv step. 03:41:23 INFO - Running pre-action listener: _resource_record_pre_action 03:41:23 INFO - Running main action method: create_virtualenv 03:41:23 INFO - Creating virtualenv /builds/slave/test/build/venv 03:41:23 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 03:41:23 INFO - Copy/paste: /tools/buildbot/bin/python /builds/slave/test/scripts/external_tools/virtualenv/virtualenv.py --always-copy /builds/slave/test/build/venv 03:41:23 INFO - Using partial env: {'VIRTUALENV_NO_DOWNLOAD': '1'} 03:41:24 INFO - Using real prefix '/usr' 03:41:24 INFO - New python executable in /builds/slave/test/build/venv/bin/python 03:41:24 INFO - Overwriting /builds/slave/test/build/venv/lib/python2.7/distutils/__init__.py with new content 03:41:28 INFO - Installing setuptools, pip, wheel...done. 03:41:28 INFO - Return code: 0 03:41:28 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv 03:41:28 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')]} 03:41:28 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 03:41:28 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')]} 03:41:28 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 03:41:28 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 0x17811f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x194ba80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1aeecc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1aebe60>, '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 0x1aecd60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1aed1f0>, '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': 'df17445c3590ff7897617a0e00000225-1508755261.676070-755970385', '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 03:41:28 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 03:41:28 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 03:41:28 INFO - Using env: {'DISPLAY': ':0', 03:41:28 INFO - 'HOME': '/home/cltbld', 03:41:28 INFO - 'LANG': 'en_US.UTF-8', 03:41:28 INFO - 'LANGUAGE': 'en_US:en', 03:41:28 INFO - 'LOGNAME': 'cltbld', 03:41:28 INFO - 'MAIL': '/var/mail/cltbld', 03:41:28 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:41:28 INFO - 'MOZ_NO_REMOTE': '1', 03:41:28 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:41:28 INFO - 'NO_EM_RESTART': '1', 03:41:28 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:41:28 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:41:28 INFO - 'PWD': '/builds/slave/test', 03:41:28 INFO - 'SHELL': '/bin/bash', 03:41:28 INFO - 'SHLVL': '1', 03:41:28 INFO - 'TERM': 'linux', 03:41:28 INFO - 'TMOUT': '86400', 03:41:28 INFO - 'USER': 'cltbld', 03:41:28 INFO - 'XDG_SESSION_COOKIE': 'df17445c3590ff7897617a0e00000225-1508755261.676070-755970385', 03:41:28 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:41:28 INFO - '_': '/tools/buildbot/bin/python'} 03:41:28 INFO - Ignoring indexes: https://pypi.python.org/simple 03:41:28 INFO - Requirement already satisfied (use --upgrade to upgrade): pip>=1.5 in ./venv/lib/python2.7/site-packages 03:41:28 INFO - Return code: 0 03:41:28 INFO - Installing psutil>=3.1.1 into virtualenv /builds/slave/test/build/venv 03:41:28 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')]} 03:41:28 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 03:41:28 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')]} 03:41:28 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 03:41:28 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 0x17811f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x194ba80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1aeecc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1aebe60>, '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 0x1aecd60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1aed1f0>, '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': 'df17445c3590ff7897617a0e00000225-1508755261.676070-755970385', '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 03:41:28 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 03:41:28 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 03:41:28 INFO - Using env: {'DISPLAY': ':0', 03:41:28 INFO - 'HOME': '/home/cltbld', 03:41:28 INFO - 'LANG': 'en_US.UTF-8', 03:41:28 INFO - 'LANGUAGE': 'en_US:en', 03:41:28 INFO - 'LOGNAME': 'cltbld', 03:41:28 INFO - 'MAIL': '/var/mail/cltbld', 03:41:28 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:41:28 INFO - 'MOZ_NO_REMOTE': '1', 03:41:28 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:41:28 INFO - 'NO_EM_RESTART': '1', 03:41:28 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:41:28 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:41:28 INFO - 'PWD': '/builds/slave/test', 03:41:28 INFO - 'SHELL': '/bin/bash', 03:41:28 INFO - 'SHLVL': '1', 03:41:28 INFO - 'TERM': 'linux', 03:41:28 INFO - 'TMOUT': '86400', 03:41:28 INFO - 'USER': 'cltbld', 03:41:28 INFO - 'XDG_SESSION_COOKIE': 'df17445c3590ff7897617a0e00000225-1508755261.676070-755970385', 03:41:28 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:41:28 INFO - '_': '/tools/buildbot/bin/python'} 03:41:29 INFO - Ignoring indexes: https://pypi.python.org/simple 03:41:29 INFO - Collecting psutil>=3.1.1 03:41:30 INFO - Installing collected packages: psutil 03:41:30 INFO - Successfully installed psutil-3.1.1 03:41:30 INFO - Return code: 0 03:41:30 INFO - Installing mozsystemmonitor==0.3 into virtualenv /builds/slave/test/build/venv 03:41: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')]} 03:41:30 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 03:41: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')]} 03:41:30 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 03:41:30 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 0x17811f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x194ba80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1aeecc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1aebe60>, '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 0x1aecd60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1aed1f0>, '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': 'df17445c3590ff7897617a0e00000225-1508755261.676070-755970385', '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 03:41:30 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 03:41:30 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 03:41:30 INFO - Using env: {'DISPLAY': ':0', 03:41:30 INFO - 'HOME': '/home/cltbld', 03:41:30 INFO - 'LANG': 'en_US.UTF-8', 03:41:30 INFO - 'LANGUAGE': 'en_US:en', 03:41:30 INFO - 'LOGNAME': 'cltbld', 03:41:30 INFO - 'MAIL': '/var/mail/cltbld', 03:41:30 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:41:30 INFO - 'MOZ_NO_REMOTE': '1', 03:41:30 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:41:30 INFO - 'NO_EM_RESTART': '1', 03:41:30 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:41:30 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:41:30 INFO - 'PWD': '/builds/slave/test', 03:41:30 INFO - 'SHELL': '/bin/bash', 03:41:30 INFO - 'SHLVL': '1', 03:41:30 INFO - 'TERM': 'linux', 03:41:30 INFO - 'TMOUT': '86400', 03:41:30 INFO - 'USER': 'cltbld', 03:41:30 INFO - 'XDG_SESSION_COOKIE': 'df17445c3590ff7897617a0e00000225-1508755261.676070-755970385', 03:41:30 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:41:30 INFO - '_': '/tools/buildbot/bin/python'} 03:41:30 INFO - Ignoring indexes: https://pypi.python.org/simple 03:41:30 INFO - Collecting mozsystemmonitor==0.3 03:41:31 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.3) 03:41:31 INFO - Installing collected packages: mozsystemmonitor 03:41:31 INFO - Successfully installed mozsystemmonitor-0.3 03:41:31 INFO - Return code: 0 03:41:31 INFO - Installing jsonschema==2.5.1 into virtualenv /builds/slave/test/build/venv 03:41:31 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')]} 03:41:31 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 03:41:31 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')]} 03:41:31 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 03:41:31 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 0x17811f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x194ba80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1aeecc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1aebe60>, '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 0x1aecd60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1aed1f0>, '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': 'df17445c3590ff7897617a0e00000225-1508755261.676070-755970385', '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 03:41:31 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 03:41:31 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 03:41:31 INFO - Using env: {'DISPLAY': ':0', 03:41:31 INFO - 'HOME': '/home/cltbld', 03:41:31 INFO - 'LANG': 'en_US.UTF-8', 03:41:31 INFO - 'LANGUAGE': 'en_US:en', 03:41:31 INFO - 'LOGNAME': 'cltbld', 03:41:31 INFO - 'MAIL': '/var/mail/cltbld', 03:41:31 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:41:31 INFO - 'MOZ_NO_REMOTE': '1', 03:41:31 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:41:31 INFO - 'NO_EM_RESTART': '1', 03:41:31 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:41:31 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:41:31 INFO - 'PWD': '/builds/slave/test', 03:41:31 INFO - 'SHELL': '/bin/bash', 03:41:31 INFO - 'SHLVL': '1', 03:41:31 INFO - 'TERM': 'linux', 03:41:31 INFO - 'TMOUT': '86400', 03:41:31 INFO - 'USER': 'cltbld', 03:41:31 INFO - 'XDG_SESSION_COOKIE': 'df17445c3590ff7897617a0e00000225-1508755261.676070-755970385', 03:41:31 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:41:31 INFO - '_': '/tools/buildbot/bin/python'} 03:41:32 INFO - Ignoring indexes: https://pypi.python.org/simple 03:41:32 INFO - Collecting jsonschema==2.5.1 03:41:33 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/jsonschema-2.5.1-py2.py3-none-any.whl 03:41:33 INFO - Collecting functools32; python_version == "2.7" (from jsonschema==2.5.1) 03:41:34 INFO - Installing collected packages: functools32, jsonschema 03:41:34 INFO - Successfully installed functools32-3.2.3.post2 jsonschema-2.5.1 03:41:34 INFO - Return code: 0 03:41:34 INFO - Installing functools32==3.2.3-2 into virtualenv /builds/slave/test/build/venv 03:41: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')]} 03:41:34 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 03:41: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')]} 03:41:34 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 03:41: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', '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 0x17811f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x194ba80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1aeecc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1aebe60>, '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 0x1aecd60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1aed1f0>, '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': 'df17445c3590ff7897617a0e00000225-1508755261.676070-755970385', '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 03:41: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', 'functools32==3.2.3-2'] in /builds/slave/test/build 03:41: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 functools32==3.2.3-2 03:41:34 INFO - Using env: {'DISPLAY': ':0', 03:41:34 INFO - 'HOME': '/home/cltbld', 03:41:34 INFO - 'LANG': 'en_US.UTF-8', 03:41:34 INFO - 'LANGUAGE': 'en_US:en', 03:41:34 INFO - 'LOGNAME': 'cltbld', 03:41:34 INFO - 'MAIL': '/var/mail/cltbld', 03:41:34 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:41:34 INFO - 'MOZ_NO_REMOTE': '1', 03:41:34 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:41:34 INFO - 'NO_EM_RESTART': '1', 03:41:34 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:41:34 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:41:34 INFO - 'PWD': '/builds/slave/test', 03:41:34 INFO - 'SHELL': '/bin/bash', 03:41:34 INFO - 'SHLVL': '1', 03:41:34 INFO - 'TERM': 'linux', 03:41:34 INFO - 'TMOUT': '86400', 03:41:34 INFO - 'USER': 'cltbld', 03:41:34 INFO - 'XDG_SESSION_COOKIE': 'df17445c3590ff7897617a0e00000225-1508755261.676070-755970385', 03:41:34 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:41:34 INFO - '_': '/tools/buildbot/bin/python'} 03:41:35 INFO - Ignoring indexes: https://pypi.python.org/simple 03:41:35 INFO - Requirement already satisfied (use --upgrade to upgrade): functools32==3.2.3-2 in ./venv/lib/python2.7/site-packages 03:41:36 INFO - Return code: 0 03:41:36 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv 03:41:36 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')]} 03:41:36 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 03:41:36 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')]} 03:41:36 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 03:41:36 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 0x17811f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x194ba80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1aeecc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1aebe60>, '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 0x1aecd60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1aed1f0>, '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': 'df17445c3590ff7897617a0e00000225-1508755261.676070-755970385', '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 03:41:36 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 03:41:36 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 03:41:36 INFO - Using env: {'DISPLAY': ':0', 03:41:36 INFO - 'HOME': '/home/cltbld', 03:41:36 INFO - 'LANG': 'en_US.UTF-8', 03:41:36 INFO - 'LANGUAGE': 'en_US:en', 03:41:36 INFO - 'LOGNAME': 'cltbld', 03:41:36 INFO - 'MAIL': '/var/mail/cltbld', 03:41:36 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:41:36 INFO - 'MOZ_NO_REMOTE': '1', 03:41:36 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:41:36 INFO - 'NO_EM_RESTART': '1', 03:41:36 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:41:36 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:41:36 INFO - 'PWD': '/builds/slave/test', 03:41:36 INFO - 'SHELL': '/bin/bash', 03:41:36 INFO - 'SHLVL': '1', 03:41:36 INFO - 'TERM': 'linux', 03:41:36 INFO - 'TMOUT': '86400', 03:41:36 INFO - 'USER': 'cltbld', 03:41:36 INFO - 'XDG_SESSION_COOKIE': 'df17445c3590ff7897617a0e00000225-1508755261.676070-755970385', 03:41:36 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:41:36 INFO - '_': '/tools/buildbot/bin/python'} 03:41:37 INFO - Ignoring indexes: https://pypi.python.org/simple 03:41:37 INFO - Collecting blobuploader==1.2.4 03:41:38 INFO - Collecting requests==1.2.3. (from blobuploader==1.2.4) 03:41:39 INFO - Collecting docopt==0.6.1 (from blobuploader==1.2.4) 03:41:40 INFO - Installing collected packages: requests, docopt, blobuploader 03:41:41 INFO - Successfully installed blobuploader-1.2.4 docopt-0.6.1 requests-1.2.3 03:41:41 INFO - Return code: 0 03:41:41 INFO - Installing None into virtualenv /builds/slave/test/build/venv 03:41:41 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')]} 03:41:41 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 03:41:41 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')]} 03:41:41 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 03:41:41 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 0x17811f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x194ba80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1aeecc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1aebe60>, '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 0x1aecd60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1aed1f0>, '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': 'df17445c3590ff7897617a0e00000225-1508755261.676070-755970385', '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 03:41:41 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 03:41:41 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 03:41:41 INFO - Using env: {'DISPLAY': ':0', 03:41:41 INFO - 'HOME': '/home/cltbld', 03:41:41 INFO - 'LANG': 'en_US.UTF-8', 03:41:41 INFO - 'LANGUAGE': 'en_US:en', 03:41:41 INFO - 'LOGNAME': 'cltbld', 03:41:41 INFO - 'MAIL': '/var/mail/cltbld', 03:41:41 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:41:41 INFO - 'MOZ_NO_REMOTE': '1', 03:41:41 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:41:41 INFO - 'NO_EM_RESTART': '1', 03:41:41 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:41:41 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:41:41 INFO - 'PWD': '/builds/slave/test', 03:41:41 INFO - 'SHELL': '/bin/bash', 03:41:41 INFO - 'SHLVL': '1', 03:41:41 INFO - 'TERM': 'linux', 03:41:41 INFO - 'TMOUT': '86400', 03:41:41 INFO - 'USER': 'cltbld', 03:41:41 INFO - 'XDG_SESSION_COOKIE': 'df17445c3590ff7897617a0e00000225-1508755261.676070-755970385', 03:41:41 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:41:41 INFO - '_': '/tools/buildbot/bin/python'} 03:41:41 INFO - Ignoring indexes: https://pypi.python.org/simple 03:41:41 INFO - Processing /builds/slave/test/build/tests/mozbase/manifestparser 03:41:41 INFO - Processing /builds/slave/test/build/tests/mozbase/mozcrash 03:41:41 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdebug 03:41:42 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdevice 03:41:42 INFO - Processing /builds/slave/test/build/tests/mozbase/mozfile 03:41:42 INFO - Processing /builds/slave/test/build/tests/mozbase/mozhttpd 03:41:42 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinfo 03:41:42 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinstall 03:41:43 INFO - Processing /builds/slave/test/build/tests/mozbase/mozleak 03:41:43 INFO - Processing /builds/slave/test/build/tests/mozbase/mozlog 03:41:43 INFO - Processing /builds/slave/test/build/tests/mozbase/moznetwork 03:41:43 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprocess 03:41:43 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprofile 03:41:43 INFO - Processing /builds/slave/test/build/tests/mozbase/mozrunner 03:41:44 INFO - Processing /builds/slave/test/build/tests/mozbase/mozscreenshot 03:41:44 INFO - Processing /builds/slave/test/build/tests/mozbase/moztest 03:41:44 INFO - Processing /builds/slave/test/build/tests/mozbase/mozversion 03:41:44 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion 03:41:44 INFO - Running setup.py install for manifestparser: started 03:41:44 INFO - Running setup.py install for manifestparser: finished with status 'done' 03:41:44 INFO - Running setup.py install for mozcrash: started 03:41:45 INFO - Running setup.py install for mozcrash: finished with status 'done' 03:41:45 INFO - Running setup.py install for mozdebug: started 03:41:45 INFO - Running setup.py install for mozdebug: finished with status 'done' 03:41:45 INFO - Running setup.py install for mozdevice: started 03:41:45 INFO - Running setup.py install for mozdevice: finished with status 'done' 03:41:45 INFO - Running setup.py install for mozfile: started 03:41:45 INFO - Running setup.py install for mozfile: finished with status 'done' 03:41:45 INFO - Running setup.py install for mozhttpd: started 03:41:45 INFO - Running setup.py install for mozhttpd: finished with status 'done' 03:41:45 INFO - Running setup.py install for mozinfo: started 03:41:46 INFO - Running setup.py install for mozinfo: finished with status 'done' 03:41:46 INFO - Running setup.py install for mozInstall: started 03:41:46 INFO - Running setup.py install for mozInstall: finished with status 'done' 03:41:46 INFO - Running setup.py install for mozleak: started 03:41:46 INFO - Running setup.py install for mozleak: finished with status 'done' 03:41:46 INFO - Running setup.py install for mozlog: started 03:41:46 INFO - Running setup.py install for mozlog: finished with status 'done' 03:41:46 INFO - Running setup.py install for moznetwork: started 03:41:47 INFO - Running setup.py install for moznetwork: finished with status 'done' 03:41:47 INFO - Running setup.py install for mozprocess: started 03:41:47 INFO - Running setup.py install for mozprocess: finished with status 'done' 03:41:47 INFO - Running setup.py install for mozprofile: started 03:41:47 INFO - Running setup.py install for mozprofile: finished with status 'done' 03:41:47 INFO - Running setup.py install for mozrunner: started 03:41:47 INFO - Running setup.py install for mozrunner: finished with status 'done' 03:41:47 INFO - Running setup.py install for mozscreenshot: started 03:41:48 INFO - Running setup.py install for mozscreenshot: finished with status 'done' 03:41:48 INFO - Running setup.py install for moztest: started 03:41:48 INFO - Running setup.py install for moztest: finished with status 'done' 03:41:48 INFO - Running setup.py install for mozversion: started 03:41:48 INFO - Running setup.py install for mozversion: finished with status 'done' 03:41:48 INFO - Successfully installed manifestparser-1.1 mozInstall-1.13 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.28 mozrunner-6.13 mozscreenshot-0.1 moztest-0.8 mozversion-1.4 03:41:48 INFO - Return code: 0 03:41:48 INFO - Installing None into virtualenv /builds/slave/test/build/venv 03:41: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')]} 03:41:48 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 03:41: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')]} 03:41:48 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 03:41:48 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 0x17811f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x194ba80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1aeecc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1aebe60>, '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 0x1aecd60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1aed1f0>, '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': 'df17445c3590ff7897617a0e00000225-1508755261.676070-755970385', '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 03:41:48 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 03:41:48 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 03:41:48 INFO - Using env: {'DISPLAY': ':0', 03:41:48 INFO - 'HOME': '/home/cltbld', 03:41:48 INFO - 'LANG': 'en_US.UTF-8', 03:41:48 INFO - 'LANGUAGE': 'en_US:en', 03:41:48 INFO - 'LOGNAME': 'cltbld', 03:41:48 INFO - 'MAIL': '/var/mail/cltbld', 03:41:48 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:41:48 INFO - 'MOZ_NO_REMOTE': '1', 03:41:48 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:41:48 INFO - 'NO_EM_RESTART': '1', 03:41:48 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:41:48 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:41:48 INFO - 'PWD': '/builds/slave/test', 03:41:48 INFO - 'SHELL': '/bin/bash', 03:41:48 INFO - 'SHLVL': '1', 03:41:48 INFO - 'TERM': 'linux', 03:41:48 INFO - 'TMOUT': '86400', 03:41:48 INFO - 'USER': 'cltbld', 03:41:48 INFO - 'XDG_SESSION_COOKIE': 'df17445c3590ff7897617a0e00000225-1508755261.676070-755970385', 03:41:48 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:41:48 INFO - '_': '/tools/buildbot/bin/python'} 03:41:49 INFO - Ignoring indexes: https://pypi.python.org/simple 03:41:49 INFO - Processing /builds/slave/test/build/tests/mozbase/manifestparser 03:41:49 INFO - Requirement already satisfied (use --upgrade to upgrade): manifestparser==1.1 from file:///builds/slave/test/build/tests/mozbase/manifestparser in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 1)) 03:41:49 INFO - Processing /builds/slave/test/build/tests/mozbase/mozcrash 03:41:49 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)) 03:41:49 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdebug 03:41:49 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)) 03:41:49 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdevice 03:41:50 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)) 03:41:50 INFO - Processing /builds/slave/test/build/tests/mozbase/mozfile 03:41:50 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)) 03:41:50 INFO - Processing /builds/slave/test/build/tests/mozbase/mozhttpd 03:41:50 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)) 03:41:50 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinfo 03:41:50 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)) 03:41:50 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinstall 03:41:50 INFO - Requirement already satisfied (use --upgrade to upgrade): mozInstall==1.13 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)) 03:41:50 INFO - Processing /builds/slave/test/build/tests/mozbase/mozleak 03:41:51 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)) 03:41:51 INFO - Processing /builds/slave/test/build/tests/mozbase/mozlog 03:41:51 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)) 03:41:51 INFO - Processing /builds/slave/test/build/tests/mozbase/moznetwork 03:41:51 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)) 03:41:51 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprocess 03:41:51 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)) 03:41:51 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprofile 03:41:51 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile==0.28 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)) 03:41:51 INFO - Processing /builds/slave/test/build/tests/mozbase/mozrunner 03:41:52 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)) 03:41:52 INFO - Processing /builds/slave/test/build/tests/mozbase/mozscreenshot 03:41:52 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)) 03:41:52 INFO - Processing /builds/slave/test/build/tests/mozbase/moztest 03:41:52 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)) 03:41:52 INFO - Processing /builds/slave/test/build/tests/mozbase/mozversion 03:41:52 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)) 03:41:52 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)) 03:41:52 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)) 03:41:52 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)) 03:41:52 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)) 03:41:52 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)) 03:41:52 INFO - Requirement already satisfied (use --upgrade to upgrade): requests in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozInstall==1.13->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 8)) 03:41:52 INFO - Collecting blessings>=1.3 (from mozlog==3.5->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 03:41:53 INFO - Installing collected packages: blessings 03:41:53 INFO - Successfully installed blessings-1.6 03:41:53 INFO - Return code: 0 03:41:53 INFO - Done creating virtualenv /builds/slave/test/build/venv. 03:41:53 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 03:41:53 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 03:41:54 INFO - Reading from file tmpfile_stdout 03:41:54 INFO - Reading from file tmpfile_stderr 03:41:54 INFO - Current package versions: 03:41:54 INFO - blessings == 1.6 03:41:54 INFO - blobuploader == 1.2.4 03:41:54 INFO - docopt == 0.6.1 03:41:54 INFO - functools32 == 3.2.3.post2 03:41:54 INFO - jsonschema == 2.5.1 03:41:54 INFO - manifestparser == 1.1 03:41:54 INFO - mozInstall == 1.13 03:41:54 INFO - mozcrash == 1.0 03:41:54 INFO - mozdebug == 0.1 03:41:54 INFO - mozdevice == 0.51 03:41:54 INFO - mozfile == 1.2 03:41:54 INFO - mozhttpd == 0.7 03:41:54 INFO - mozinfo == 0.10 03:41:54 INFO - mozleak == 0.1 03:41:54 INFO - mozlog == 3.5 03:41:54 INFO - moznetwork == 0.27 03:41:54 INFO - mozprocess == 0.25 03:41:54 INFO - mozprofile == 0.28 03:41:54 INFO - mozrunner == 6.13 03:41:54 INFO - mozscreenshot == 0.1 03:41:54 INFO - mozsystemmonitor == 0.3 03:41:54 INFO - moztest == 0.8 03:41:54 INFO - mozversion == 1.4 03:41:54 INFO - psutil == 3.1.1 03:41:54 INFO - requests == 1.2.3 03:41:54 INFO - Installing None into virtualenv /builds/slave/test/build/venv 03:41:54 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')]} 03:41:54 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 03:41:54 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')]} 03:41:54 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 03:41:54 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 0x17811f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x194ba80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1aeecc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1aebe60>, '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 0x1aecd60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1aed1f0>, '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': 'df17445c3590ff7897617a0e00000225-1508755261.676070-755970385', '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 03:41:54 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 03:41:54 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 03:41:54 INFO - Using env: {'DISPLAY': ':0', 03:41:54 INFO - 'HOME': '/home/cltbld', 03:41:54 INFO - 'LANG': 'en_US.UTF-8', 03:41:54 INFO - 'LANGUAGE': 'en_US:en', 03:41:54 INFO - 'LOGNAME': 'cltbld', 03:41:54 INFO - 'MAIL': '/var/mail/cltbld', 03:41:54 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:41:54 INFO - 'MOZ_NO_REMOTE': '1', 03:41:54 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:41:54 INFO - 'NO_EM_RESTART': '1', 03:41:54 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:41:54 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:41:54 INFO - 'PWD': '/builds/slave/test', 03:41:54 INFO - 'SHELL': '/bin/bash', 03:41:54 INFO - 'SHLVL': '1', 03:41:54 INFO - 'TERM': 'linux', 03:41:54 INFO - 'TMOUT': '86400', 03:41:54 INFO - 'USER': 'cltbld', 03:41:54 INFO - 'XDG_SESSION_COOKIE': 'df17445c3590ff7897617a0e00000225-1508755261.676070-755970385', 03:41:54 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:41:54 INFO - '_': '/tools/buildbot/bin/python'} 03:41:54 INFO - Ignoring indexes: https://pypi.python.org/simple 03:41:54 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)) 03:41:54 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)) 03:41:54 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)) 03:41:54 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)) 03:41:54 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)) 03:41:54 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)) 03:41:54 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)) 03:41:54 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)) 03:41:54 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)) 03:41:54 INFO - Collecting simplejson>=2.1.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 10)) 03:41:55 INFO - Collecting requests>=2.9.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 03:41:57 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)) 03:41:57 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)) 03:41:57 INFO - Installing collected packages: simplejson, requests 03:41:57 INFO - Found existing installation: requests 1.2.3 03:41:57 INFO - Uninstalling requests-1.2.3: 03:41:57 INFO - Successfully uninstalled requests-1.2.3 03:41:57 INFO - Successfully installed requests-2.13.0 simplejson-3.3.0 03:41:57 INFO - Return code: 0 03:41:57 INFO - Installing jsonschema into virtualenv /builds/slave/test/build/venv 03:41:57 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')]} 03:41:57 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 03:41:57 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')]} 03:41:57 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 03:41:57 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 0x17811f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x194ba80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1aeecc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1aebe60>, '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 0x1aecd60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1aed1f0>, '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': 'df17445c3590ff7897617a0e00000225-1508755261.676070-755970385', '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 03:41:57 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 03:41:57 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 03:41:57 INFO - Using env: {'DISPLAY': ':0', 03:41:57 INFO - 'HOME': '/home/cltbld', 03:41:57 INFO - 'LANG': 'en_US.UTF-8', 03:41:57 INFO - 'LANGUAGE': 'en_US:en', 03:41:57 INFO - 'LOGNAME': 'cltbld', 03:41:57 INFO - 'MAIL': '/var/mail/cltbld', 03:41:57 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:41:57 INFO - 'MOZ_NO_REMOTE': '1', 03:41:57 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:41:57 INFO - 'NO_EM_RESTART': '1', 03:41:57 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:41:57 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:41:57 INFO - 'PWD': '/builds/slave/test', 03:41:57 INFO - 'SHELL': '/bin/bash', 03:41:57 INFO - 'SHLVL': '1', 03:41:57 INFO - 'TERM': 'linux', 03:41:57 INFO - 'TMOUT': '86400', 03:41:57 INFO - 'USER': 'cltbld', 03:41:57 INFO - 'XDG_SESSION_COOKIE': 'df17445c3590ff7897617a0e00000225-1508755261.676070-755970385', 03:41:57 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:41:57 INFO - '_': '/tools/buildbot/bin/python'} 03:41:57 INFO - Ignoring indexes: https://pypi.python.org/simple 03:41:57 INFO - Requirement already satisfied (use --upgrade to upgrade): jsonschema in ./venv/lib/python2.7/site-packages 03:41:57 INFO - Requirement already satisfied (use --upgrade to upgrade): functools32; python_version == "2.7" in ./venv/lib/python2.7/site-packages (from jsonschema) 03:41:57 INFO - Return code: 0 03:41:57 INFO - Running post-action listener: _resource_record_post_action 03:41:57 INFO - Running post-action listener: _start_resource_monitoring 03:41:57 INFO - Starting resource monitoring. 03:41:57 INFO - [mozharness: 2017-10-23 10:41:57.985510Z] Finished create-virtualenv step (success) 03:41:57 INFO - [mozharness: 2017-10-23 10:41:57.986013Z] Running install step. 03:41:57 INFO - Running pre-action listener: _resource_record_pre_action 03:41:57 INFO - Running main action method: install 03:41:57 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 03:41:57 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 03:41:58 INFO - Reading from file tmpfile_stdout 03:41:58 INFO - Reading from file tmpfile_stderr 03:41:58 INFO - Detecting whether we're running mozinstall >=1.0... 03:41:58 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h'] 03:41:58 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h 03:41:58 INFO - Reading from file tmpfile_stdout 03:41:58 INFO - Output received: 03:41:58 INFO - Usage: mozinstall [options] installer 03:41:58 INFO - Options: 03:41:58 INFO - -h, --help show this help message and exit 03:41:58 INFO - -d DEST, --destination=DEST 03:41:58 INFO - Directory to install application into. [default: 03:41:58 INFO - "/builds/slave/test"] 03:41:58 INFO - --app=APP Application being installed. [default: firefox] 03:41:58 INFO - mkdir: /builds/slave/test/build/application 03:41:58 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'] 03:41:58 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall /builds/slave/test/build/target.tar.bz2 --destination /builds/slave/test/build/application 03:42:16 INFO - Reading from file tmpfile_stdout 03:42:16 INFO - Output received: 03:42:16 INFO - /builds/slave/test/build/application/firefox/firefox 03:42:16 INFO - Running post-action listener: _resource_record_post_action 03:42:16 INFO - [mozharness: 2017-10-23 10:42:16.810723Z] Finished install step (success) 03:42:16 INFO - [mozharness: 2017-10-23 10:42:16.810864Z] Running setup-mitmproxy step. 03:42:16 INFO - Running pre-action listener: _resource_record_pre_action 03:42:16 INFO - Running main action method: setup_mitmproxy 03:42:16 INFO - Skipping: mitmproxy is not required 03:42:16 INFO - Running post-action listener: _resource_record_post_action 03:42:16 INFO - [mozharness: 2017-10-23 10:42:16.811385Z] Finished setup-mitmproxy step (success) 03:42:16 INFO - [mozharness: 2017-10-23 10:42:16.811488Z] Running run-tests step. 03:42:16 INFO - Running pre-action listener: _resource_record_pre_action 03:42:16 INFO - Running pre-action listener: _set_gcov_prefix 03:42:16 INFO - Running main action method: run_tests 03:42:16 WARNING - Try message not found. 03:42:16 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version'] 03:42:16 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version 03:42:16 INFO - Python 2.7.3 03:42:16 INFO - Return code: 0 03:42:16 INFO - grabbing minidump binary from tooltool 03:42:16 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')]} 03:42:16 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 0x1aebe60>, '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 0x1aecd60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1aed1f0>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1 03:42:16 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 03:42:16 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 03:42:16 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 03:42:16 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache 03:42:16 INFO - Return code: 0 03:42:16 INFO - Chmoding /builds/slave/test/build/linux64-minidump_stackwalk to 0755 03:42:16 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir 03:42:16 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir 03:42:16 INFO - ENV: RUST_BACKTRACE is now full 03:42:16 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/linux64-minidump_stackwalk 03:42:16 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir 03:42:16 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--branchName', 'Firefox', '--suite', 'g4-e10s', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/IkLgTIrmT-yJ9Iu89kKCDQ/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-021', '--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 03:42:16 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/tests/talos/talos/run_tests.py --branchName Firefox --suite g4-e10s --executablePath /builds/slave/test/build/application/firefox/firefox --symbolsPath https://queue.taskcluster.net/v1/task/IkLgTIrmT-yJ9Iu89kKCDQ/artifacts/public/build/target.crashreporter-symbols.zip --title talos-linux64-ix-021 --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 03:42:16 INFO - Using env: {'DISPLAY': ':0', 03:42:16 INFO - 'HOME': '/home/cltbld', 03:42:16 INFO - 'LANG': 'en_US.UTF-8', 03:42:16 INFO - 'LANGUAGE': 'en_US:en', 03:42:16 INFO - 'LOGNAME': 'cltbld', 03:42:16 INFO - 'MAIL': '/var/mail/cltbld', 03:42:16 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 03:42:16 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 03:42:16 INFO - 'MOZ_ACCELERATED': '1', 03:42:16 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:42:16 INFO - 'MOZ_NO_REMOTE': '1', 03:42:16 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 03:42:16 INFO - 'MOZ_WEBRENDER': '1', 03:42:16 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:42:16 INFO - 'NO_EM_RESTART': '1', 03:42:16 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:42:16 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:42:16 INFO - 'PWD': '/builds/slave/test', 03:42:16 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 03:42:16 INFO - 'RUST_BACKTRACE': 'full', 03:42:16 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 03:42:16 INFO - 'SHELL': '/bin/bash', 03:42:16 INFO - 'SHLVL': '1', 03:42:16 INFO - 'TERM': 'linux', 03:42:16 INFO - 'TMOUT': '86400', 03:42:16 INFO - 'USER': 'cltbld', 03:42:16 INFO - 'XDG_SESSION_COOKIE': 'df17445c3590ff7897617a0e00000225-1508755261.676070-755970385', 03:42:16 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:42:16 INFO - '_': '/tools/buildbot/bin/python'} 03:42:16 INFO - Calling ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--branchName', 'Firefox', '--suite', 'g4-e10s', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/IkLgTIrmT-yJ9Iu89kKCDQ/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-021', '--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 03:42:17 INFO - mozversion application_buildid: 20171023093937 03:42:17 INFO - mozversion application_changeset: d49501f258b105c5e2dcd0a59896ec1ceabf726b 03:42:17 INFO - mozversion application_display_name: Nightly 03:42:17 INFO - mozversion application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384} 03:42:17 INFO - mozversion application_name: Firefox 03:42:17 INFO - mozversion application_remotingname: firefox 03:42:17 INFO - mozversion application_repository: https://hg.mozilla.org/mozilla-central 03:42:17 INFO - mozversion application_vendor: Mozilla 03:42:17 INFO - mozversion application_version: 58.0a1 03:42:17 INFO - mozversion platform_buildid: 20171023093937 03:42:17 INFO - mozversion platform_changeset: d49501f258b105c5e2dcd0a59896ec1ceabf726b 03:42:17 INFO - mozversion platform_repository: https://hg.mozilla.org/mozilla-central 03:42:17 INFO - mozversion platform_version: 58.0a1 03:42:17 INFO - using testdate: 1508755337 03:42:17 INFO - actual date: 1508755337 03:42:17 INFO - starting webserver on 'localhost:52263' 03:42:17 INFO - SUITE-START | Running 2 tests 03:42:17 INFO - TEST-START | basic_compositor_video 03:42:17 INFO - Initialising browser for basic_compositor_video test... 03:42:17 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:52263/getInfo.html -profile /tmp/tmpKbUNj8/profile 03:42:17 INFO - TEST-INFO | started process 30254 (/builds/slave/test/build/application/firefox/firefox http://localhost:52263/getInfo.html) 03:42:24 INFO - TEST-INFO | 30254: exit 0 03:42:24 INFO - Browser initialized. 03:42:24 INFO - Running cycle 1/1 for basic_compositor_video test... 03:42:24 INFO - Using env: {'DISPLAY': ':0', 03:42:24 INFO - 'HOME': '/home/cltbld', 03:42:24 INFO - 'JSGC_DISABLE_POISONING': '1', 03:42:24 INFO - 'LANG': 'en_US.UTF-8', 03:42:24 INFO - 'LANGUAGE': 'en_US:en', 03:42:24 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 03:42:24 INFO - 'LOGNAME': 'cltbld', 03:42:24 INFO - 'MAIL': '/var/mail/cltbld', 03:42:24 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 03:42:24 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 03:42:24 INFO - 'MOZ_ACCELERATED': '1', 03:42:24 INFO - 'MOZ_CRASHREPORTER': '1', 03:42:24 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:42:24 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 03:42:24 INFO - 'MOZ_NO_REMOTE': '1', 03:42:24 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 03:42:24 INFO - 'MOZ_WEBRENDER': '1', 03:42:24 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:42:24 INFO - 'NO_EM_RESTART': '1', 03:42:24 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:42:24 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:42:24 INFO - 'PWD': '/builds/slave/test', 03:42:24 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 03:42:24 INFO - 'RUST_BACKTRACE': 'full', 03:42:24 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 03:42:24 INFO - 'SHELL': '/bin/bash', 03:42:24 INFO - 'SHLVL': '1', 03:42:24 INFO - 'TERM': 'linux', 03:42:24 INFO - 'TMOUT': '86400', 03:42:24 INFO - 'USER': 'cltbld', 03:42:24 INFO - 'XDG_SESSION_COOKIE': 'df17445c3590ff7897617a0e00000225-1508755261.676070-755970385', 03:42:24 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:42:24 INFO - '_': '/tools/buildbot/bin/python'} 03:42:24 INFO - TEST-INFO | started process 30500 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpKbUNj8/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/video/video.manifest.develop -tpnoisy -tpcycles 1 -tppagecycles 12) 03:42:25 INFO - PID 30500 | WebRender - OpenGL version new 3.2.0 NVIDIA 361.42 03:42:25 INFO - PID 30500 | WebRender - OpenGL version new 3.2.0 NVIDIA 361.42 03:42:25 INFO - PID 30500 | 03:42:25 INFO - PID 30500 | (/builds/slave/test/build/application/firefox/firefox:30563): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 03:42:25 INFO - PID 30500 | 03:43:11 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1_startup = 2.498584512905912 ms/frame 03:43:11 INFO - PID 30500 | 03:43:11 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1_inclip = 2.4367722289890374 ms/frame 03:43:11 INFO - PID 30500 | 03:43:11 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1.1_startup = 2.4550613747954175 ms/frame 03:43:11 INFO - PID 30500 | 03:43:11 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 2.4575061425061424 ms/frame 03:43:11 INFO - PID 30500 | 03:43:11 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_2_startup = 3.0338169868554092 ms/frame 03:43:11 INFO - PID 30500 | 03:43:11 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.0121234939759054 ms/frame 03:43:11 INFO - PID 30500 | 03:43:11 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1_startup = 4.504474474474474 ms/frame 03:43:11 INFO - PID 30500 | 03:43:11 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1_inclip = 4.311153017241379 ms/frame 03:43:11 INFO - PID 30500 | 03:43:11 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.202689075630249 ms/frame 03:43:11 INFO - PID 30500 | 03:43:11 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.177160751565763 ms/frame 03:43:11 INFO - PID 30500 | 03:43:11 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_2_startup = 4.70273510971787 ms/frame 03:43:11 INFO - PID 30500 | 03:43:11 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_2_inclip = 4.619999999999998 ms/frame 03:43:11 INFO - PID 30500 | 03:43:11 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1_startup = 6.948171296296306 ms/frame 03:43:11 INFO - PID 30500 | 03:43:11 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1_inclip = 6.689933110367871 ms/frame 03:43:11 INFO - PID 30500 | 03:43:11 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 6.946145833333334 ms/frame 03:43:11 INFO - PID 30500 | 03:43:11 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 6.691454849498337 ms/frame 03:43:11 INFO - PID 30500 | 03:43:11 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_2_startup = 6.9291685912240055 ms/frame 03:43:11 INFO - PID 30500 | 03:43:11 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_2_inclip = 6.690903010033451 ms/frame 03:43:11 INFO - PID 30500 | 03:43:11 INFO - PID 30500 | Cycle 1(1): loaded http://localhost:52263/tests/video/video_playback.html (next: http://localhost:52263/tests/video/video_playback.html) 03:43:57 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1_startup = 2.4337591240875915 ms/frame 03:43:57 INFO - PID 30500 | 03:43:57 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1_inclip = 2.4011944777911163 ms/frame 03:43:57 INFO - PID 30500 | 03:43:57 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1.1_startup = 2.4594590163934424 ms/frame 03:43:57 INFO - PID 30500 | 03:43:57 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 2.4448594132029333 ms/frame 03:43:57 INFO - PID 30500 | 03:43:57 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_2_startup = 3.0243245967741945 ms/frame 03:43:57 INFO - PID 30500 | 03:43:57 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.0128313253012027 ms/frame 03:43:57 INFO - PID 30500 | 03:43:57 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1_startup = 4.196090909090912 ms/frame 03:43:57 INFO - PID 30500 | 03:43:57 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1_inclip = 4.202426470588234 ms/frame 03:43:57 INFO - PID 30500 | 03:43:57 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.238693502824862 ms/frame 03:43:57 INFO - PID 30500 | 03:43:57 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.2294608879492595 ms/frame 03:43:57 INFO - PID 30500 | 03:43:57 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_2_startup = 4.763269841269842 ms/frame 03:43:57 INFO - PID 30500 | 03:43:57 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_2_inclip = 4.696960093896711 ms/frame 03:43:57 INFO - PID 30500 | 03:43:57 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1_startup = 6.897540229885058 ms/frame 03:43:57 INFO - PID 30500 | 03:43:57 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1_inclip = 6.688996655518402 ms/frame 03:43:57 INFO - PID 30500 | 03:43:57 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 6.946817129629633 ms/frame 03:43:57 INFO - PID 30500 | 03:43:57 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 6.735404040404044 ms/frame 03:43:57 INFO - PID 30500 | 03:43:57 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_2_startup = 6.929422632794463 ms/frame 03:43:57 INFO - PID 30500 | 03:43:57 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_2_inclip = 6.71169463087248 ms/frame 03:43:57 INFO - PID 30500 | 03:43:57 INFO - PID 30500 | Cycle 1(2): loaded http://localhost:52263/tests/video/video_playback.html (next: http://localhost:52263/tests/video/video_playback.html) 03:44:43 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1_startup = 2.4391951219512196 ms/frame 03:44:43 INFO - PID 30500 | 03:44:43 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1_inclip = 2.410403614457832 ms/frame 03:44:43 INFO - PID 30500 | 03:44:43 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1.1_startup = 2.479520661157024 ms/frame 03:44:43 INFO - PID 30500 | 03:44:43 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 2.447937576499389 ms/frame 03:44:43 INFO - PID 30500 | 03:44:43 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_2_startup = 3.0188179074446677 ms/frame 03:44:43 INFO - PID 30500 | 03:44:43 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.0076240601503756 ms/frame 03:44:43 INFO - PID 30500 | 03:44:43 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1_startup = 4.189846368715084 ms/frame 03:44:43 INFO - PID 30500 | 03:44:43 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1_inclip = 4.123639175257733 ms/frame 03:44:43 INFO - PID 30500 | 03:44:43 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.219571026722923 ms/frame 03:44:43 INFO - PID 30500 | 03:44:43 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.141770186335409 ms/frame 03:44:43 INFO - PID 30500 | 03:44:43 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_2_startup = 4.73978672985782 ms/frame 03:44:43 INFO - PID 30500 | 03:44:43 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_2_inclip = 4.68498829039813 ms/frame 03:44:43 INFO - PID 30500 | 03:44:43 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1_startup = 6.928418013856824 ms/frame 03:44:43 INFO - PID 30500 | 03:44:43 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1_inclip = 6.733989898989884 ms/frame 03:44:43 INFO - PID 30500 | 03:44:43 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 6.929676674364903 ms/frame 03:44:43 INFO - PID 30500 | 03:44:43 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 6.734629629629622 ms/frame 03:44:43 INFO - PID 30500 | 03:44:43 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_2_startup = 6.99441724941724 ms/frame 03:44:43 INFO - PID 30500 | 03:44:43 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_2_inclip = 6.6688999999999945 ms/frame 03:44:43 INFO - PID 30500 | 03:44:43 INFO - PID 30500 | Cycle 1(3): loaded http://localhost:52263/tests/video/video_playback.html (next: http://localhost:52263/tests/video/video_playback.html) 03:45:29 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1_startup = 2.465402629416598 ms/frame 03:45:29 INFO - PID 30500 | 03:45:29 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1_inclip = 2.424587878787879 ms/frame 03:45:29 INFO - PID 30500 | 03:45:29 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1.1_startup = 2.4716309719934104 ms/frame 03:45:29 INFO - PID 30500 | 03:45:29 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 2.4423565323565333 ms/frame 03:45:29 INFO - PID 30500 | 03:45:29 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_2_startup = 3.0188682092555323 ms/frame 03:45:29 INFO - PID 30500 | 03:45:29 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.008203007518797 ms/frame 03:45:29 INFO - PID 30500 | 03:45:29 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1_startup = 4.330064935064933 ms/frame 03:45:29 INFO - PID 30500 | 03:45:29 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1_inclip = 4.264669509594885 ms/frame 03:45:29 INFO - PID 30500 | 03:45:29 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.336257225433524 ms/frame 03:45:29 INFO - PID 30500 | 03:45:29 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.319870410367168 ms/frame 03:45:29 INFO - PID 30500 | 03:45:29 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_2_startup = 4.681170046801873 ms/frame 03:45:29 INFO - PID 30500 | 03:45:29 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_2_inclip = 4.673411214953274 ms/frame 03:45:29 INFO - PID 30500 | 03:45:29 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1_startup = 6.913652073732714 ms/frame 03:45:29 INFO - PID 30500 | 03:45:29 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1_inclip = 6.690284280936469 ms/frame 03:45:29 INFO - PID 30500 | 03:45:29 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 6.89863218390806 ms/frame 03:45:29 INFO - PID 30500 | 03:45:29 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 6.6685833333333235 ms/frame 03:45:29 INFO - PID 30500 | 03:45:29 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_2_startup = 7.010969626168223 ms/frame 03:45:29 INFO - PID 30500 | 03:45:29 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_2_inclip = 6.66971666666667 ms/frame 03:45:29 INFO - PID 30500 | 03:45:29 INFO - PID 30500 | Cycle 1(4): loaded http://localhost:52263/tests/video/video_playback.html (next: http://localhost:52263/tests/video/video_playback.html) 03:46:15 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1_startup = 2.425897332255457 ms/frame 03:46:15 INFO - PID 30500 | 03:46:15 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1_inclip = 2.405096153846154 ms/frame 03:46:15 INFO - PID 30500 | 03:46:15 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1.1_startup = 2.475313531353135 ms/frame 03:46:15 INFO - PID 30500 | 03:46:15 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 2.450925245098039 ms/frame 03:46:15 INFO - PID 30500 | 03:46:15 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_2_startup = 3.0213242698892238 ms/frame 03:46:15 INFO - PID 30500 | 03:46:15 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.0131551204819287 ms/frame 03:46:15 INFO - PID 30500 | 03:46:15 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1_startup = 4.4184977908689245 ms/frame 03:46:15 INFO - PID 30500 | 03:46:15 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1_inclip = 4.386304824561409 ms/frame 03:46:15 INFO - PID 30500 | 03:46:15 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.226323943661975 ms/frame 03:46:15 INFO - PID 30500 | 03:46:15 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.158866943866946 ms/frame 03:46:15 INFO - PID 30500 | 03:46:15 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_2_startup = 4.623089368258863 ms/frame 03:46:15 INFO - PID 30500 | 03:46:15 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_2_inclip = 4.629687499999995 ms/frame 03:46:15 INFO - PID 30500 | 03:46:15 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1_startup = 6.929572748267892 ms/frame 03:46:15 INFO - PID 30500 | 03:46:15 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1_inclip = 6.713624161073837 ms/frame 03:46:15 INFO - PID 30500 | 03:46:15 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 6.914677419354842 ms/frame 03:46:15 INFO - PID 30500 | 03:46:15 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 6.691020066889625 ms/frame 03:46:15 INFO - PID 30500 | 03:46:15 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_2_startup = 6.945937500000009 ms/frame 03:46:15 INFO - PID 30500 | 03:46:15 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_2_inclip = 6.734579124579119 ms/frame 03:46:15 INFO - PID 30500 | 03:46:15 INFO - PID 30500 | Cycle 1(5): loaded http://localhost:52263/tests/video/video_playback.html (next: http://localhost:52263/tests/video/video_playback.html) 03:47:01 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1_startup = 2.441806346623271 ms/frame 03:47:01 INFO - PID 30500 | 03:47:01 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1_inclip = 2.5414358322744595 ms/frame 03:47:01 INFO - PID 30500 | 03:47:01 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1.1_startup = 2.45140931372549 ms/frame 03:47:01 INFO - PID 30500 | 03:47:01 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 2.4451833740831304 ms/frame 03:47:01 INFO - PID 30500 | 03:47:01 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_2_startup = 3.0365080971659917 ms/frame 03:47:01 INFO - PID 30500 | 03:47:01 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.017526395173455 ms/frame 03:47:01 INFO - PID 30500 | 03:47:01 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1_startup = 4.149439834024896 ms/frame 03:47:01 INFO - PID 30500 | 03:47:01 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1_inclip = 4.149315352697098 ms/frame 03:47:01 INFO - PID 30500 | 03:47:01 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.539462934947049 ms/frame 03:47:01 INFO - PID 30500 | 03:47:01 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.5151354401805825 ms/frame 03:47:01 INFO - PID 30500 | 03:47:01 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_2_startup = 4.823585209003216 ms/frame 03:47:01 INFO - PID 30500 | 03:47:01 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_2_inclip = 4.830652173913042 ms/frame 03:47:01 INFO - PID 30500 | 03:47:01 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1_startup = 6.961914153132248 ms/frame 03:47:01 INFO - PID 30500 | 03:47:01 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1_inclip = 6.6676833333333345 ms/frame 03:47:01 INFO - PID 30500 | 03:47:01 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 6.929318706697469 ms/frame 03:47:01 INFO - PID 30500 | 03:47:01 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 6.691036789297644 ms/frame 03:47:01 INFO - PID 30500 | 03:47:01 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_2_startup = 6.977534883720922 ms/frame 03:47:01 INFO - PID 30500 | 03:47:01 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_2_inclip = 6.667133333333331 ms/frame 03:47:01 INFO - PID 30500 | 03:47:01 INFO - PID 30500 | Cycle 1(6): loaded http://localhost:52263/tests/video/video_playback.html (next: http://localhost:52263/tests/video/video_playback.html) 03:47:47 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1_startup = 2.437558895207149 ms/frame 03:47:47 INFO - PID 30500 | 03:47:47 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1_inclip = 2.4103433734939754 ms/frame 03:47:47 INFO - PID 30500 | 03:47:47 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1.1_startup = 2.4556996726677576 ms/frame 03:47:47 INFO - PID 30500 | 03:47:47 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 2.4545153374233144 ms/frame 03:47:47 INFO - PID 30500 | 03:47:47 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_2_startup = 3.024853830645162 ms/frame 03:47:47 INFO - PID 30500 | 03:47:47 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.0083308270676676 ms/frame 03:47:47 INFO - PID 30500 | 03:47:47 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1_startup = 4.432341211225994 ms/frame 03:47:47 INFO - PID 30500 | 03:47:47 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1_inclip = 4.34951086956522 ms/frame 03:47:47 INFO - PID 30500 | 03:47:47 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.225760563380283 ms/frame 03:47:47 INFO - PID 30500 | 03:47:47 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.151047717842324 ms/frame 03:47:47 INFO - PID 30500 | 03:47:47 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_2_startup = 4.6816536661466435 ms/frame 03:47:47 INFO - PID 30500 | 03:47:47 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_2_inclip = 4.640243619489558 ms/frame 03:47:47 INFO - PID 30500 | 03:47:47 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1_startup = 6.944999999999995 ms/frame 03:47:47 INFO - PID 30500 | 03:47:47 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1_inclip = 6.733872053872051 ms/frame 03:47:47 INFO - PID 30500 | 03:47:47 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 6.881662844036711 ms/frame 03:47:47 INFO - PID 30500 | 03:47:47 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 6.692140468227415 ms/frame 03:47:47 INFO - PID 30500 | 03:47:47 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_2_startup = 6.912707373271885 ms/frame 03:47:47 INFO - PID 30500 | 03:47:47 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_2_inclip = 6.779508474576277 ms/frame 03:47:47 INFO - PID 30500 | 03:47:47 INFO - PID 30500 | Cycle 1(7): loaded http://localhost:52263/tests/video/video_playback.html (next: http://localhost:52263/tests/video/video_playback.html) 03:48:33 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1_startup = 2.4351542207792205 ms/frame 03:48:33 INFO - PID 30500 | 03:48:33 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1_inclip = 2.4129855247285894 ms/frame 03:48:33 INFO - PID 30500 | 03:48:33 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1.1_startup = 2.471943986820428 ms/frame 03:48:33 INFO - PID 30500 | 03:48:33 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 2.4456112469437667 ms/frame 03:48:33 INFO - PID 30500 | 03:48:33 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_2_startup = 3.034216380182002 ms/frame 03:48:33 INFO - PID 30500 | 03:48:33 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.012763554216868 ms/frame 03:48:33 INFO - PID 30500 | 03:48:33 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1_startup = 4.274252136752139 ms/frame 03:48:33 INFO - PID 30500 | 03:48:33 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1_inclip = 4.264957356076758 ms/frame 03:48:33 INFO - PID 30500 | 03:48:33 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.274643874643874 ms/frame 03:48:33 INFO - PID 30500 | 03:48:33 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.264275053304903 ms/frame 03:48:33 INFO - PID 30500 | 03:48:33 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_2_startup = 4.659704968944097 ms/frame 03:48:33 INFO - PID 30500 | 03:48:33 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_2_inclip = 4.640266821345712 ms/frame 03:48:33 INFO - PID 30500 | 03:48:33 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1_startup = 6.914297235023042 ms/frame 03:48:33 INFO - PID 30500 | 03:48:33 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1_inclip = 6.688979933110359 ms/frame 03:48:33 INFO - PID 30500 | 03:48:33 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 6.9796046511627985 ms/frame 03:48:33 INFO - PID 30500 | 03:48:33 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 6.711929530201338 ms/frame 03:48:33 INFO - PID 30500 | 03:48:33 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_2_startup = 6.961322505800451 ms/frame 03:48:33 INFO - PID 30500 | 03:48:33 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_2_inclip = 6.736531986531986 ms/frame 03:48:33 INFO - PID 30500 | 03:48:33 INFO - PID 30500 | Cycle 1(8): loaded http://localhost:52263/tests/video/video_playback.html (next: http://localhost:52263/tests/video/video_playback.html) 03:49:19 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1_startup = 2.4353652597402595 ms/frame 03:49:19 INFO - PID 30500 | 03:49:19 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1_inclip = 2.4097108433734946 ms/frame 03:49:19 INFO - PID 30500 | 03:49:19 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1.1_startup = 2.475742574257426 ms/frame 03:49:19 INFO - PID 30500 | 03:49:19 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 2.433832116788322 ms/frame 03:49:19 INFO - PID 30500 | 03:49:19 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_2_startup = 3.0181438631790742 ms/frame 03:49:19 INFO - PID 30500 | 03:49:19 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.0129442771084327 ms/frame 03:49:19 INFO - PID 30500 | 03:49:19 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1_startup = 4.518388554216869 ms/frame 03:49:19 INFO - PID 30500 | 03:49:19 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1_inclip = 4.464944196428568 ms/frame 03:49:19 INFO - PID 30500 | 03:49:19 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.380839416058394 ms/frame 03:49:19 INFO - PID 30500 | 03:49:19 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.265063965884867 ms/frame 03:49:19 INFO - PID 30500 | 03:49:19 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_2_startup = 4.733052050473188 ms/frame 03:49:19 INFO - PID 30500 | 03:49:19 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_2_inclip = 4.662680652680646 ms/frame 03:49:19 INFO - PID 30500 | 03:49:19 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1_startup = 6.881307339449541 ms/frame 03:49:19 INFO - PID 30500 | 03:49:19 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1_inclip = 6.734461279461287 ms/frame 03:49:19 INFO - PID 30500 | 03:49:19 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 6.945185185185185 ms/frame 03:49:19 INFO - PID 30500 | 03:49:19 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 6.66714999999999 ms/frame 03:49:19 INFO - PID 30500 | 03:49:19 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_2_startup = 6.914216589861761 ms/frame 03:49:19 INFO - PID 30500 | 03:49:19 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_2_inclip = 6.667849999999986 ms/frame 03:49:19 INFO - PID 30500 | 03:49:19 INFO - PID 30500 | Cycle 1(9): loaded http://localhost:52263/tests/video/video_playback.html (next: http://localhost:52263/tests/video/video_playback.html) 03:50:05 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1_startup = 2.4295303643724693 ms/frame 03:50:05 INFO - PID 30500 | 03:50:05 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1_inclip = 2.4019987995198075 ms/frame 03:50:05 INFO - PID 30500 | 03:50:05 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1.1_startup = 2.479619834710744 ms/frame 03:50:05 INFO - PID 30500 | 03:50:05 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 2.4452017114914417 ms/frame 03:50:05 INFO - PID 30500 | 03:50:05 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_2_startup = 3.0214199395770396 ms/frame 03:50:05 INFO - PID 30500 | 03:50:05 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.0120632530120486 ms/frame 03:50:05 INFO - PID 30500 | 03:50:05 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1_startup = 4.18536262203626 ms/frame 03:50:05 INFO - PID 30500 | 03:50:05 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1_inclip = 4.150269709543569 ms/frame 03:50:05 INFO - PID 30500 | 03:50:05 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.594379785604902 ms/frame 03:50:05 INFO - PID 30500 | 03:50:05 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.566472602739729 ms/frame 03:50:05 INFO - PID 30500 | 03:50:05 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_2_startup = 4.659961180124223 ms/frame 03:50:05 INFO - PID 30500 | 03:50:05 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_2_inclip = 4.59785057471264 ms/frame 03:50:05 INFO - PID 30500 | 03:50:05 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1_startup = 6.850799086757986 ms/frame 03:50:05 INFO - PID 30500 | 03:50:05 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1_inclip = 6.7143791946308795 ms/frame 03:50:05 INFO - PID 30500 | 03:50:05 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 6.897804597701162 ms/frame 03:50:05 INFO - PID 30500 | 03:50:05 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 6.690551839464878 ms/frame 03:50:05 INFO - PID 30500 | 03:50:05 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_2_startup = 6.8649542334096125 ms/frame 03:50:05 INFO - PID 30500 | 03:50:05 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_2_inclip = 6.669083333333329 ms/frame 03:50:05 INFO - PID 30500 | 03:50:05 INFO - PID 30500 | Cycle 1(10): loaded http://localhost:52263/tests/video/video_playback.html (next: http://localhost:52263/tests/video/video_playback.html) 03:50:51 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1_startup = 2.4353814935064935 ms/frame 03:50:51 INFO - PID 30500 | 03:50:51 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1_inclip = 2.4022509003601438 ms/frame 03:50:51 INFO - PID 30500 | 03:50:51 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1.1_startup = 2.4774401321222133 ms/frame 03:50:51 INFO - PID 30500 | 03:50:51 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 2.4426190476190466 ms/frame 03:50:51 INFO - PID 30500 | 03:50:51 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_2_startup = 3.0435953346855973 ms/frame 03:50:51 INFO - PID 30500 | 03:50:51 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.013185240963857 ms/frame 03:50:51 INFO - PID 30500 | 03:50:51 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1_startup = 4.56646118721461 ms/frame 03:50:51 INFO - PID 30500 | 03:50:51 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1_inclip = 4.466060267857147 ms/frame 03:50:51 INFO - PID 30500 | 03:50:51 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.172642559109876 ms/frame 03:50:51 INFO - PID 30500 | 03:50:51 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.150280082987555 ms/frame 03:50:51 INFO - PID 30500 | 03:50:51 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_2_startup = 4.694984350547733 ms/frame 03:50:51 INFO - PID 30500 | 03:50:51 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_2_inclip = 4.620854503464208 ms/frame 03:50:51 INFO - PID 30500 | 03:50:51 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1_startup = 6.913617511520742 ms/frame 03:50:51 INFO - PID 30500 | 03:50:51 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1_inclip = 6.7572466216216105 ms/frame 03:50:51 INFO - PID 30500 | 03:50:51 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 6.89740229885058 ms/frame 03:50:51 INFO - PID 30500 | 03:50:51 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 6.805918367346922 ms/frame 03:50:51 INFO - PID 30500 | 03:50:51 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_2_startup = 6.994125874125881 ms/frame 03:50:51 INFO - PID 30500 | 03:50:51 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_2_inclip = 6.714530201342283 ms/frame 03:50:51 INFO - PID 30500 | 03:50:51 INFO - PID 30500 | Cycle 1(11): loaded http://localhost:52263/tests/video/video_playback.html (next: http://localhost:52263/tests/video/video_playback.html) 03:51:37 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1_startup = 2.4156884057971015 ms/frame 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1_inclip = 2.3932894736842103 ms/frame 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1.1_startup = 2.469670781893004 ms/frame 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 2.4392012195121944 ms/frame 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_2_startup = 3.0221148036253784 ms/frame 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.0083759398496235 ms/frame 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1_startup = 4.386805555555557 ms/frame 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1_inclip = 4.367543668122269 ms/frame 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.190733240223467 ms/frame 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.176659707724424 ms/frame 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_2_startup = 4.815794542536118 ms/frame 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | testsrc.480p.60fps.webm_scale_2_inclip = 4.7850956937799 ms/frame 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1_startup = 6.984872093023245 ms/frame 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1_inclip = 6.783000000000002 ms/frame 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 6.882683486238529 ms/frame 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 6.691153846153842 ms/frame 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_2_startup = 6.914654377880182 ms/frame 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | testsrc.1080p.60fps.mp4_scale_2_inclip = 6.714798657718128 ms/frame 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | Cycle 1(12): loaded http://localhost:52263/tests/video/video_playback.html (next: http://localhost:52263/tests/video/video_playback.html) 03:51:37 INFO - PID 30500 | __start_tp_report 03:51:37 INFO - PID 30500 | _x_x_mozilla_page_load 03:51:37 INFO - PID 30500 | _x_x_mozilla_page_load_details 03:51:37 INFO - PID 30500 | |i|pagename|runs| 03:51:37 INFO - PID 30500 | |0;240p.120fps.mp4_scale_1_startup;2.498584512905912;2.4337591240875915;2.4391951219512196;2.465402629416598;2.425897332255457;2.441806346623271;2.437558895207149;2.4351542207792205;2.4353652597402595;2.4295303643724693;2.4353814935064935;2.4156884057971015 03:51:37 INFO - PID 30500 | |1;240p.120fps.mp4_scale_1_inclip;2.4367722289890374;2.4011944777911163;2.410403614457832;2.424587878787879;2.405096153846154;2.5414358322744595;2.4103433734939754;2.4129855247285894;2.4097108433734946;2.4019987995198075;2.4022509003601438;2.3932894736842103 03:51:37 INFO - PID 30500 | |2;240p.120fps.mp4_scale_1.1_startup;2.4550613747954175;2.4594590163934424;2.479520661157024;2.4716309719934104;2.475313531353135;2.45140931372549;2.4556996726677576;2.471943986820428;2.475742574257426;2.479619834710744;2.4774401321222133;2.469670781893004 03:51:37 INFO - PID 30500 | |3;240p.120fps.mp4_scale_1.1_inclip;2.4575061425061424;2.4448594132029333;2.447937576499389;2.4423565323565333;2.450925245098039;2.4451833740831304;2.4545153374233144;2.4456112469437667;2.433832116788322;2.4452017114914417;2.4426190476190466;2.4392012195121944 03:51:37 INFO - PID 30500 | |4;240p.120fps.mp4_scale_2_startup;3.0338169868554092;3.0243245967741945;3.0188179074446677;3.0188682092555323;3.0213242698892238;3.0365080971659917;3.024853830645162;3.034216380182002;3.0181438631790742;3.0214199395770396;3.0435953346855973;3.0221148036253784 03:51:37 INFO - PID 30500 | |5;240p.120fps.mp4_scale_2_inclip;3.0121234939759054;3.0128313253012027;3.0076240601503756;3.008203007518797;3.0131551204819287;3.017526395173455;3.0083308270676676;3.012763554216868;3.0129442771084327;3.0120632530120486;3.013185240963857;3.0083759398496235 03:51:37 INFO - PID 30500 | |6;480p.60fps.webm_scale_1_startup;4.504474474474474;4.196090909090912;4.189846368715084;4.330064935064933;4.4184977908689245;4.149439834024896;4.432341211225994;4.274252136752139;4.518388554216869;4.18536262203626;4.56646118721461;4.386805555555557 03:51:37 INFO - PID 30500 | |7;480p.60fps.webm_scale_1_inclip;4.311153017241379;4.202426470588234;4.123639175257733;4.264669509594885;4.386304824561409;4.149315352697098;4.34951086956522;4.264957356076758;4.464944196428568;4.150269709543569;4.466060267857147;4.367543668122269 03:51:37 INFO - PID 30500 | |8;480p.60fps.webm_scale_1.1_startup;4.202689075630249;4.238693502824862;4.219571026722923;4.336257225433524;4.226323943661975;4.539462934947049;4.225760563380283;4.274643874643874;4.380839416058394;4.594379785604902;4.172642559109876;4.190733240223467 03:51:37 INFO - PID 30500 | |9;480p.60fps.webm_scale_1.1_inclip;4.177160751565763;4.2294608879492595;4.141770186335409;4.319870410367168;4.158866943866946;4.5151354401805825;4.151047717842324;4.264275053304903;4.265063965884867;4.566472602739729;4.150280082987555;4.176659707724424 03:51:37 INFO - PID 30500 | |10;480p.60fps.webm_scale_2_startup;4.70273510971787;4.763269841269842;4.73978672985782;4.681170046801873;4.623089368258863;4.823585209003216;4.6816536661466435;4.659704968944097;4.733052050473188;4.659961180124223;4.694984350547733;4.815794542536118 03:51:37 INFO - PID 30500 | |11;480p.60fps.webm_scale_2_inclip;4.619999999999998;4.696960093896711;4.68498829039813;4.673411214953274;4.629687499999995;4.830652173913042;4.640243619489558;4.640266821345712;4.662680652680646;4.59785057471264;4.620854503464208;4.7850956937799 03:51:37 INFO - PID 30500 | |12;1080p.60fps.mp4_scale_1_startup;6.948171296296306;6.897540229885058;6.928418013856824;6.913652073732714;6.929572748267892;6.961914153132248;6.944999999999995;6.914297235023042;6.881307339449541;6.850799086757986;6.913617511520742;6.984872093023245 03:51:37 INFO - PID 30500 | |13;1080p.60fps.mp4_scale_1_inclip;6.689933110367871;6.688996655518402;6.733989898989884;6.690284280936469;6.713624161073837;6.6676833333333345;6.733872053872051;6.688979933110359;6.734461279461287;6.7143791946308795;6.7572466216216105;6.783000000000002 03:51:37 INFO - PID 30500 | |14;1080p.60fps.mp4_scale_1.1_startup;6.946145833333334;6.946817129629633;6.929676674364903;6.89863218390806;6.914677419354842;6.929318706697469;6.881662844036711;6.9796046511627985;6.945185185185185;6.897804597701162;6.89740229885058;6.882683486238529 03:51:37 INFO - PID 30500 | |15;1080p.60fps.mp4_scale_1.1_inclip;6.691454849498337;6.735404040404044;6.734629629629622;6.6685833333333235;6.691020066889625;6.691036789297644;6.692140468227415;6.711929530201338;6.66714999999999;6.690551839464878;6.805918367346922;6.691153846153842 03:51:37 INFO - PID 30500 | |16;1080p.60fps.mp4_scale_2_startup;6.9291685912240055;6.929422632794463;6.99441724941724;7.010969626168223;6.945937500000009;6.977534883720922;6.912707373271885;6.961322505800451;6.914216589861761;6.8649542334096125;6.994125874125881;6.914654377880182 03:51:37 INFO - PID 30500 | |17;1080p.60fps.mp4_scale_2_inclip;6.690903010033451;6.71169463087248;6.6688999999999945;6.66971666666667;6.734579124579119;6.667133333333331;6.779508474576277;6.736531986531986;6.667849999999986;6.669083333333329;6.714530201342283;6.714798657718128 03:51:37 INFO - PID 30500 | __end_tp_report 03:51:37 INFO - PID 30500 | __start_cc_report 03:51:37 INFO - PID 30500 | _x_x_mozilla_cycle_collect,585 03:51:37 INFO - PID 30500 | __end_cc_report 03:51:37 INFO - PID 30500 | __startTimestamp1508755897583__endTimestamp 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | ------- Summary: start ------- 03:51:37 INFO - PID 30500 | Number of tests: 18 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | [#0] 240p.120fps.mp4_scale_1_startup Cycles:12 Average:2.44 Median:2.44 stddev:0.02 (0.9%) stddev-sans-first:0.01 03:51:37 INFO - PID 30500 | Values: 2.5 2.4 2.4 2.5 2.4 2.4 2.4 2.4 2.4 2.4 2.4 2.4 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | [#1] 240p.120fps.mp4_scale_1_inclip Cycles:12 Average:2.42 Median:2.41 stddev:0.04 (1.6%) stddev-sans-first:0.04 03:51:37 INFO - PID 30500 | Values: 2.4 2.4 2.4 2.4 2.4 2.5 2.4 2.4 2.4 2.4 2.4 2.4 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | [#2] 240p.120fps.mp4_scale_1.1_startup Cycles:12 Average:2.47 Median:2.47 stddev:0.01 (0.4%) stddev-sans-first:0.01 03:51:37 INFO - PID 30500 | Values: 2.5 2.5 2.5 2.5 2.5 2.5 2.5 2.5 2.5 2.5 2.5 2.5 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | [#3] 240p.120fps.mp4_scale_1.1_inclip Cycles:12 Average:2.45 Median:2.45 stddev:0.01 (0.3%) stddev-sans-first:0.01 03:51:37 INFO - PID 30500 | Values: 2.5 2.4 2.4 2.4 2.5 2.4 2.5 2.4 2.4 2.4 2.4 2.4 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | [#4] 240p.120fps.mp4_scale_2_startup Cycles:12 Average:3.03 Median:3.02 stddev:0.01 (0.3%) stddev-sans-first:0.01 03:51:37 INFO - PID 30500 | Values: 3.0 3.0 3.0 3.0 3.0 3.0 3.0 3.0 3.0 3.0 3.0 3.0 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | [#5] 240p.120fps.mp4_scale_2_inclip Cycles:12 Average:3.01 Median:3.01 stddev:0.00 (0.1%) stddev-sans-first:0.00 03:51:37 INFO - PID 30500 | Values: 3.0 3.0 3.0 3.0 3.0 3.0 3.0 3.0 3.0 3.0 3.0 3.0 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | [#6] 480p.60fps.webm_scale_1_startup Cycles:12 Average:4.35 Median:4.40 stddev:0.15 (3.3%) stddev-sans-first:0.14 03:51:37 INFO - PID 30500 | Values: 4.5 4.2 4.2 4.3 4.4 4.1 4.4 4.3 4.5 4.2 4.6 4.4 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | [#7] 480p.60fps.webm_scale_1_inclip Cycles:12 Average:4.29 Median:4.33 stddev:0.12 (2.8%) stddev-sans-first:0.13 03:51:37 INFO - PID 30500 | Values: 4.3 4.2 4.1 4.3 4.4 4.1 4.3 4.3 4.5 4.2 4.5 4.4 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | [#8] 480p.60fps.webm_scale_1.1_startup Cycles:12 Average:4.30 Median:4.26 stddev:0.14 (3.3%) stddev-sans-first:0.14 03:51:37 INFO - PID 30500 | Values: 4.2 4.2 4.2 4.3 4.2 4.5 4.2 4.3 4.4 4.6 4.2 4.2 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | [#9] 480p.60fps.webm_scale_1.1_inclip Cycles:12 Average:4.26 Median:4.25 stddev:0.14 (3.4%) stddev-sans-first:0.15 03:51:37 INFO - PID 30500 | Values: 4.2 4.2 4.1 4.3 4.2 4.5 4.2 4.3 4.3 4.6 4.2 4.2 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | [#10] 480p.60fps.webm_scale_2_startup Cycles:12 Average:4.71 Median:4.72 stddev:0.06 (1.3%) stddev-sans-first:0.07 03:51:37 INFO - PID 30500 | Values: 4.7 4.8 4.7 4.7 4.6 4.8 4.7 4.7 4.7 4.7 4.7 4.8 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | [#11] 480p.60fps.webm_scale_2_inclip Cycles:12 Average:4.67 Median:4.67 stddev:0.07 (1.5%) stddev-sans-first:0.07 03:51:37 INFO - PID 30500 | Values: 4.6 4.7 4.7 4.7 4.6 4.8 4.6 4.6 4.7 4.6 4.6 4.8 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | [#12] 1080p.60fps.mp4_scale_1_startup Cycles:12 Average:6.92 Median:6.93 stddev:0.04 (0.5%) stddev-sans-first:0.04 03:51:37 INFO - PID 30500 | Values: 6.9 6.9 6.9 6.9 6.9 7.0 6.9 6.9 6.9 6.9 6.9 7.0 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | [#13] 1080p.60fps.mp4_scale_1_inclip Cycles:12 Average:6.72 Median:6.72 stddev:0.03 (0.5%) stddev-sans-first:0.03 03:51:37 INFO - PID 30500 | Values: 6.7 6.7 6.7 6.7 6.7 6.7 6.7 6.7 6.7 6.7 6.8 6.8 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | [#14] 1080p.60fps.mp4_scale_1.1_startup Cycles:12 Average:6.92 Median:6.93 stddev:0.03 (0.4%) stddev-sans-first:0.03 03:51:37 INFO - PID 30500 | Values: 6.9 6.9 6.9 6.9 6.9 6.9 6.9 7.0 6.9 6.9 6.9 6.9 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | [#15] 1080p.60fps.mp4_scale_1.1_inclip Cycles:12 Average:6.71 Median:6.69 stddev:0.04 (0.6%) stddev-sans-first:0.04 03:51:37 INFO - PID 30500 | Values: 6.7 6.7 6.7 6.7 6.7 6.7 6.7 6.7 6.7 6.7 6.8 6.7 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | [#16] 1080p.60fps.mp4_scale_2_startup Cycles:12 Average:6.95 Median:6.95 stddev:0.04 (0.6%) stddev-sans-first:0.04 03:51:37 INFO - PID 30500 | Values: 6.9 6.9 7.0 7.0 6.9 7.0 6.9 7.0 6.9 6.9 7.0 6.9 03:51:37 INFO - PID 30500 | 03:51:37 INFO - PID 30500 | [#17] 1080p.60fps.mp4_scale_2_inclip Cycles:12 Average:6.70 Median:6.71 stddev:0.04 (0.5%) stddev-sans-first:0.04 03:51:37 INFO - PID 30500 | Values: 6.7 6.7 6.7 6.7 6.7 6.7 6.8 6.7 6.7 6.7 6.7 6.7 03:51:37 INFO - PID 30500 | -------- Summary: end -------- 03:51:37 INFO - PID 30500 | 03:51:38 INFO - TEST-INFO | 30500: exit 0 03:51:38 INFO - TEST-OK | basic_compositor_video | took 561019ms 03:51:38 INFO - TEST-START | glvideo 03:51:38 INFO - Initialising browser for glvideo test... 03:51:38 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:52263/getInfo.html -profile /tmp/tmpRfRceV/profile 03:51:38 INFO - TEST-INFO | started process 31753 (/builds/slave/test/build/application/firefox/firefox http://localhost:52263/getInfo.html) 03:51:45 INFO - TEST-INFO | 31753: exit 0 03:51:46 INFO - Browser initialized. 03:51:46 INFO - Running cycle 1/1 for glvideo test... 03:51:46 INFO - Using env: {'DISPLAY': ':0', 03:51:46 INFO - 'HOME': '/home/cltbld', 03:51:46 INFO - 'JSGC_DISABLE_POISONING': '1', 03:51:46 INFO - 'LANG': 'en_US.UTF-8', 03:51:46 INFO - 'LANGUAGE': 'en_US:en', 03:51:46 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 03:51:46 INFO - 'LOGNAME': 'cltbld', 03:51:46 INFO - 'MAIL': '/var/mail/cltbld', 03:51:46 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 03:51:46 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 03:51:46 INFO - 'MOZ_ACCELERATED': '1', 03:51:46 INFO - 'MOZ_CRASHREPORTER': '1', 03:51:46 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:51:46 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 03:51:46 INFO - 'MOZ_NO_REMOTE': '1', 03:51:46 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 03:51:46 INFO - 'MOZ_WEBRENDER': '1', 03:51:46 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:51:46 INFO - 'NO_EM_RESTART': '1', 03:51:46 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:51:46 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:51:46 INFO - 'PWD': '/builds/slave/test', 03:51:46 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 03:51:46 INFO - 'RUST_BACKTRACE': 'full', 03:51:46 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 03:51:46 INFO - 'SHELL': '/bin/bash', 03:51:46 INFO - 'SHLVL': '1', 03:51:46 INFO - 'TERM': 'linux', 03:51:46 INFO - 'TMOUT': '86400', 03:51:46 INFO - 'USER': 'cltbld', 03:51:46 INFO - 'XDG_SESSION_COOKIE': 'df17445c3590ff7897617a0e00000225-1508755261.676070-755970385', 03:51:46 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:51:46 INFO - '_': '/tools/buildbot/bin/python'} 03:51:46 INFO - TEST-INFO | started process 31999 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpRfRceV/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/webgl/glvideo.manifest.develop -tpnoisy -tploadnocache -tpcycles 1 -tppagecycles 5) 03:51:46 INFO - PID 31999 | WebRender - OpenGL version new 3.2.0 NVIDIA 361.42 03:51:47 INFO - PID 31999 | WebRender - OpenGL version new 3.2.0 NVIDIA 361.42 03:51:47 INFO - PID 31999 | 03:51:47 INFO - PID 31999 | (/builds/slave/test/build/application/firefox/firefox:32060): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 03:51:47 INFO - PID 31999 | 03:51:48 INFO - PID 31999 | [talos glvideo result] Mean tick time across 100 ticks: 8.84065 ms 03:51:48 INFO - PID 31999 | Cycle 1(1): loaded http://localhost:52263/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:52263/tests/webgl/benchmarks/video/video_upload.html) 03:51:50 INFO - PID 31999 | [talos glvideo result] Mean tick time across 100 ticks: 6.522800000000001 ms 03:51:50 INFO - PID 31999 | Cycle 1(2): loaded http://localhost:52263/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:52263/tests/webgl/benchmarks/video/video_upload.html) 03:51:51 INFO - PID 31999 | [talos glvideo result] Mean tick time across 100 ticks: 6.5203 ms 03:51:51 INFO - PID 31999 | Cycle 1(3): loaded http://localhost:52263/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:52263/tests/webgl/benchmarks/video/video_upload.html) 03:51:52 INFO - PID 31999 | [talos glvideo result] Mean tick time across 100 ticks: 6.604000000000001 ms 03:51:52 INFO - PID 31999 | Cycle 1(4): loaded http://localhost:52263/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:52263/tests/webgl/benchmarks/video/video_upload.html) 03:51:54 INFO - PID 31999 | [talos glvideo result] Mean tick time across 100 ticks: 6.5076 ms 03:51:54 INFO - PID 31999 | Cycle 1(5): loaded http://localhost:52263/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:52263/tests/webgl/benchmarks/video/video_upload.html) 03:51:54 INFO - PID 31999 | __start_tp_report 03:51:54 INFO - PID 31999 | _x_x_mozilla_page_load 03:51:54 INFO - PID 31999 | _x_x_mozilla_page_load_details 03:51:54 INFO - PID 31999 | |i|pagename|runs| 03:51:54 INFO - PID 31999 | |0;Mean tick time across 100 ticks: ;8.84065;6.522800000000001;6.5203;6.604000000000001;6.5076 03:51:54 INFO - PID 31999 | __end_tp_report 03:51:54 INFO - PID 31999 | __start_cc_report 03:51:54 INFO - PID 31999 | _x_x_mozilla_cycle_collect,280 03:51:54 INFO - PID 31999 | __end_cc_report 03:51:54 INFO - PID 31999 | __startTimestamp1508755914399__endTimestamp 03:51:54 INFO - PID 31999 | 03:51:54 INFO - PID 31999 | ------- Summary: start ------- 03:51:54 INFO - PID 31999 | Number of tests: 1 03:51:54 INFO - PID 31999 | 03:51:54 INFO - PID 31999 | [#0] Mean tick time across 100 ticks: Cycles:5 Average:7.00 Median:6.52 stddev:1.03 (15.8%) stddev-sans-first:0.04 03:51:54 INFO - PID 31999 | Values: 8.8 6.5 6.5 6.6 6.5 03:51:54 INFO - PID 31999 | -------- Summary: end -------- 03:51:54 INFO - PID 31999 | 03:51:54 INFO - PID 31999 | *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping 03:51:55 INFO - TEST-INFO | 31999: exit 0 03:51:55 INFO - TEST-OK | glvideo | took 16912ms 03:51:55 INFO - SUITE-END | took 577s 03:51:55 INFO - Completed test suite (00:09:38) 03:51:55 INFO - PERFHERDER_DATA: {"framework": {"name": "talos"}, "suites": [{"extraOptions": ["e10s"], "name": "basic_compositor_video", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 4.347099276214759, "subtests": [{"name": "240p.120fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [2.498584512905912, 2.4337591240875915, 2.4391951219512196, 2.465402629416598, 2.425897332255457, 2.441806346623271, 2.437558895207149, 2.4351542207792205, 2.4353652597402595, 2.4295303643724693, 2.4353814935064935, 2.4156884057971015], "value": 2.4353652597402595, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [2.4367722289890374, 2.4011944777911163, 2.410403614457832, 2.424587878787879, 2.405096153846154, 2.5414358322744595, 2.4103433734939754, 2.4129855247285894, 2.4097108433734946, 2.4019987995198075, 2.4022509003601438, 2.3932894736842103], "value": 2.4097108433734946, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [2.4550613747954175, 2.4594590163934424, 2.479520661157024, 2.4716309719934104, 2.475313531353135, 2.45140931372549, 2.4556996726677576, 2.471943986820428, 2.475742574257426, 2.479619834710744, 2.4774401321222133, 2.469670781893004], "value": 2.471943986820428, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [2.4575061425061424, 2.4448594132029333, 2.447937576499389, 2.4423565323565333, 2.450925245098039, 2.4451833740831304, 2.4545153374233144, 2.4456112469437667, 2.433832116788322, 2.4452017114914417, 2.4426190476190466, 2.4392012195121944], "value": 2.4451833740831304, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.0338169868554092, 3.0243245967741945, 3.0188179074446677, 3.0188682092555323, 3.0213242698892238, 3.0365080971659917, 3.024853830645162, 3.034216380182002, 3.0181438631790742, 3.0214199395770396, 3.0435953346855973, 3.0221148036253784], "value": 3.0221148036253784, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.0121234939759054, 3.0128313253012027, 3.0076240601503756, 3.008203007518797, 3.0131551204819287, 3.017526395173455, 3.0083308270676676, 3.012763554216868, 3.0129442771084327, 3.0120632530120486, 3.013185240963857, 3.0083759398496235], "value": 3.012763554216868, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.504474474474474, 4.196090909090912, 4.189846368715084, 4.330064935064933, 4.4184977908689245, 4.149439834024896, 4.432341211225994, 4.274252136752139, 4.518388554216869, 4.18536262203626, 4.56646118721461, 4.386805555555557], "value": 4.330064935064933, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.311153017241379, 4.202426470588234, 4.123639175257733, 4.264669509594885, 4.386304824561409, 4.149315352697098, 4.34951086956522, 4.264957356076758, 4.464944196428568, 4.150269709543569, 4.466060267857147, 4.367543668122269], "value": 4.264957356076758, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.202689075630249, 4.238693502824862, 4.219571026722923, 4.336257225433524, 4.226323943661975, 4.539462934947049, 4.225760563380283, 4.274643874643874, 4.380839416058394, 4.594379785604902, 4.172642559109876, 4.190733240223467], "value": 4.238693502824862, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.177160751565763, 4.2294608879492595, 4.141770186335409, 4.319870410367168, 4.158866943866946, 4.5151354401805825, 4.151047717842324, 4.264275053304903, 4.265063965884867, 4.566472602739729, 4.150280082987555, 4.176659707724424], "value": 4.2294608879492595, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.70273510971787, 4.763269841269842, 4.73978672985782, 4.681170046801873, 4.623089368258863, 4.823585209003216, 4.6816536661466435, 4.659704968944097, 4.733052050473188, 4.659961180124223, 4.694984350547733, 4.815794542536118], "value": 4.694984350547733, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.619999999999998, 4.696960093896711, 4.68498829039813, 4.673411214953274, 4.629687499999995, 4.830652173913042, 4.640243619489558, 4.640266821345712, 4.662680652680646, 4.59785057471264, 4.620854503464208, 4.7850956937799], "value": 4.662680652680646, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [6.948171296296306, 6.897540229885058, 6.928418013856824, 6.913652073732714, 6.929572748267892, 6.961914153132248, 6.944999999999995, 6.914297235023042, 6.881307339449541, 6.850799086757986, 6.913617511520742, 6.984872093023245], "value": 6.914297235023042, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [6.689933110367871, 6.688996655518402, 6.733989898989884, 6.690284280936469, 6.713624161073837, 6.6676833333333345, 6.733872053872051, 6.688979933110359, 6.734461279461287, 6.7143791946308795, 6.7572466216216105, 6.783000000000002], "value": 6.7143791946308795, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [6.946145833333334, 6.946817129629633, 6.929676674364903, 6.89863218390806, 6.914677419354842, 6.929318706697469, 6.881662844036711, 6.9796046511627985, 6.945185185185185, 6.897804597701162, 6.89740229885058, 6.882683486238529], "value": 6.914677419354842, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [6.691454849498337, 6.735404040404044, 6.734629629629622, 6.6685833333333235, 6.691020066889625, 6.691036789297644, 6.692140468227415, 6.711929530201338, 6.66714999999999, 6.690551839464878, 6.805918367346922, 6.691153846153842], "value": 6.691153846153842, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [6.9291685912240055, 6.929422632794463, 6.99441724941724, 7.010969626168223, 6.945937500000009, 6.977534883720922, 6.912707373271885, 6.961322505800451, 6.914216589861761, 6.8649542334096125, 6.994125874125881, 6.914654377880182], "value": 6.945937500000009, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [6.690903010033451, 6.71169463087248, 6.6688999999999945, 6.66971666666667, 6.734579124579119, 6.667133333333331, 6.779508474576277, 6.736531986531986, 6.667849999999986, 6.669083333333329, 6.714530201342283, 6.714798657718128], "value": 6.71169463087248, "unit": "ms/frame"}]}, {"lowerIsBetter": true, "subtests": [{"name": "Mean tick time across 100 ticks: ", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [8.84065, 6.522800000000001, 6.5203, 6.604000000000001, 6.5076], "value": 6.52155, "unit": "ms"}], "extraOptions": ["e10s"], "name": "glvideo", "alertThreshold": 2.0}]} 03:51:55 INFO - Return code: 0 03:51:55 INFO - Validating PERFHERDER_DATA against /builds/slave/test/scripts/external_tools/performance-artifact-schema.json 03:51:55 INFO - # TBPL SUCCESS # 03:51:55 INFO - Running post-action listener: _package_coverage_data 03:51:55 INFO - Running post-action listener: _resource_record_post_action 03:51:55 INFO - [mozharness: 2017-10-23 10:51:55.581131Z] Finished run-tests step (success) 03:51:55 INFO - Running post-run listener: _resource_record_post_run 03:51:55 INFO - Total resource usage - Wall time: 597s; CPU: 47.0%; Read bytes: 2945024; Write bytes: 437981184; Read time: 420; Write time: 522724 03:51:55 INFO - TinderboxPrint: CPU usage
46.6% 03:51:55 INFO - TinderboxPrint: I/O read bytes / time
2,945,024 / 420 03:51:55 INFO - TinderboxPrint: I/O write bytes / time
437,981,184 / 522,724 03:51:55 INFO - TinderboxPrint: CPU idle
2,391.3 (53.3%) 03:51:55 INFO - TinderboxPrint: CPU system
615.1 (13.7%) 03:51:55 INFO - TinderboxPrint: CPU user
1,454.3 (32.4%) 03:51:55 INFO - TinderboxPrint: Swap in / out
0 / 0 03:51:55 INFO - install - Wall time: 19s; CPU: 13.0%; Read bytes: 0; Write bytes: 62881792; Read time: 0; Write time: 142428 03:51:55 INFO - setup-mitmproxy - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0 03:51:55 INFO - run-tests - Wall time: 579s; CPU: 48.0%; Read bytes: 2945024; Write bytes: 311189504; Read time: 420; Write time: 326928 03:51:55 INFO - Running post-run listener: _upload_blobber_files 03:51:55 INFO - Blob upload gear active. 03:51:55 INFO - Preparing to upload files from /builds/slave/test/build/blobber_upload_dir. 03:51:55 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 03:51:55 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', '-d', '/builds/slave/test/build/blobber_upload_dir', '--output-manifest', '/builds/slave/test/build/uploaded_files.json'] 03:51:55 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 -d /builds/slave/test/build/blobber_upload_dir --output-manifest /builds/slave/test/build/uploaded_files.json 03:51:56 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 03:51:56 INFO - SNIMissingWarning 03:51:56 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 03:51:56 INFO - InsecurePlatformWarning 03:51:56 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.) 03:51:56 INFO - SubjectAltNameWarning 03:51:56 INFO - (blobuploader) - INFO - Open directory for files ... 03:51:56 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/perfherder-data.json ... 03:51:56 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 03:51:56 INFO - (blobuploader) - INFO - Uploading, attempt #1. 03:51:56 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 03:51:56 INFO - InsecurePlatformWarning 03:51:56 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.) 03:51:56 INFO - SubjectAltNameWarning 03:51:56 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 03:51:56 INFO - InsecurePlatformWarning 03:51:57 INFO - (blobuploader) - INFO - TinderboxPrint: perfherder-data.json: uploaded 03:51:57 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 03:51:57 INFO - (blobuploader) - INFO - Done attempting. 03:51:57 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/resource-usage.json ... 03:51:57 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 03:51:57 INFO - (blobuploader) - INFO - Uploading, attempt #1. 03:51:57 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 03:51:57 INFO - InsecurePlatformWarning 03:51:57 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.) 03:51:57 INFO - SubjectAltNameWarning 03:52:00 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 03:52:00 INFO - InsecurePlatformWarning 03:52:00 INFO - (blobuploader) - INFO - TinderboxPrint: resource-usage.json: uploaded 03:52:00 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 03:52:00 INFO - (blobuploader) - INFO - Done attempting. 03:52:00 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-e10s_errorsummary.log ... 03:52:00 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 03:52:00 INFO - (blobuploader) - INFO - Uploading, attempt #1. 03:52:01 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 03:52:01 INFO - InsecurePlatformWarning 03:52:01 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.) 03:52:01 INFO - SubjectAltNameWarning 03:52:01 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 03:52:01 INFO - InsecurePlatformWarning 03:52:01 INFO - (blobuploader) - INFO - TinderboxPrint: g4-e10s_errorsummary.log: uploaded 03:52:01 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 03:52:01 INFO - (blobuploader) - INFO - Done attempting. 03:52:01 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-e10s_raw.log ... 03:52:01 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 03:52:01 INFO - (blobuploader) - INFO - Uploading, attempt #1. 03:52:02 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 03:52:02 INFO - InsecurePlatformWarning 03:52:02 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.) 03:52:02 INFO - SubjectAltNameWarning 03:52:02 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 03:52:02 INFO - InsecurePlatformWarning 03:52:02 INFO - (blobuploader) - INFO - TinderboxPrint: g4-e10s_raw.log: uploaded 03:52:02 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 03:52:02 INFO - (blobuploader) - INFO - Done attempting. 03:52:02 INFO - (blobuploader) - INFO - Iteration through files over. 03:52:02 INFO - Return code: 0 03:52:02 INFO - rmtree: /builds/slave/test/build/uploaded_files.json 03:52:02 INFO - retry: Calling remove with args: ('/builds/slave/test/build/uploaded_files.json',), kwargs: {}, attempt #1 03:52:02 INFO - Setting buildbot property blobber_files to {"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/f619da024a192ea29c4909ced9db2e051c702c2eadceddcfbd8754175af0c3cc053a942bb333caac056a8f405aae72e95a3af6f8717ec3d7b58972aeeb50dfca", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/79391e19d9b72206d5e63a0c56b21e39c766c44614d42e03de49cc95e87e98b35a9496a7b6a1ad085d5893135efa75c98c33e9d86f71832dea54d863e4767ef3", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/870d1a4b20c3ec58edd8881b32e86b48cec5be75fffd52d1b6506c2c851a64064efc123c074def3c249b6d089943f6935b4b51817cd765ef1b08a0d9f6a5cc48", "g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/0f339e2ad0937af18d4d5a08133ec79405c4dda401c6c51dabba21ac933b1e06966559eb2602033a56f1a2f4a491a43b6510d725ed7c589f0cfafc59742277c6"} 03:52:02 INFO - Writing buildbot properties ['blobber_files'] to /builds/slave/test/properties/blobber_files 03:52:02 INFO - Writing to file /builds/slave/test/properties/blobber_files 03:52:02 INFO - Contents: 03:52:02 INFO - blobber_files:{"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/f619da024a192ea29c4909ced9db2e051c702c2eadceddcfbd8754175af0c3cc053a942bb333caac056a8f405aae72e95a3af6f8717ec3d7b58972aeeb50dfca", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/79391e19d9b72206d5e63a0c56b21e39c766c44614d42e03de49cc95e87e98b35a9496a7b6a1ad085d5893135efa75c98c33e9d86f71832dea54d863e4767ef3", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/870d1a4b20c3ec58edd8881b32e86b48cec5be75fffd52d1b6506c2c851a64064efc123c074def3c249b6d089943f6935b4b51817cd765ef1b08a0d9f6a5cc48", "g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/0f339e2ad0937af18d4d5a08133ec79405c4dda401c6c51dabba21ac933b1e06966559eb2602033a56f1a2f4a491a43b6510d725ed7c589f0cfafc59742277c6"} 03:52:02 INFO - Running post-run listener: copy_logs_to_upload_dir 03:52:02 INFO - Copying logs to upload dir... 03:52:02 INFO - mkdir: /builds/slave/test/build/upload/logs 03:52:02 INFO - Copying logs to upload dir... program finished with exit code 0 elapsedTime=657.541392 ========= master_lag: 0.16 ========= ========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 10 mins, 57 secs) (at 2017-10-23 03:52:03.064018) ========= ========= Started set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-10-23 03:52:03.067372) ========= 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=df17445c3590ff7897617a0e00000225-1508755261.676070-755970385 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False blobber_files:{"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/f619da024a192ea29c4909ced9db2e051c702c2eadceddcfbd8754175af0c3cc053a942bb333caac056a8f405aae72e95a3af6f8717ec3d7b58972aeeb50dfca", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/79391e19d9b72206d5e63a0c56b21e39c766c44614d42e03de49cc95e87e98b35a9496a7b6a1ad085d5893135efa75c98c33e9d86f71832dea54d863e4767ef3", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/870d1a4b20c3ec58edd8881b32e86b48cec5be75fffd52d1b6506c2c851a64064efc123c074def3c249b6d089943f6935b4b51817cd765ef1b08a0d9f6a5cc48", "g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/0f339e2ad0937af18d4d5a08133ec79405c4dda401c6c51dabba21ac933b1e06966559eb2602033a56f1a2f4a491a43b6510d725ed7c589f0cfafc59742277c6"} build_url:https://queue.taskcluster.net/v1/task/IkLgTIrmT-yJ9Iu89kKCDQ/artifacts/public/build/target.tar.bz2 program finished with exit code 0 elapsedTime=0.011367 build_url: 'https://queue.taskcluster.net/v1/task/IkLgTIrmT-yJ9Iu89kKCDQ/artifacts/public/build/target.tar.bz2' blobber_files: '{"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/f619da024a192ea29c4909ced9db2e051c702c2eadceddcfbd8754175af0c3cc053a942bb333caac056a8f405aae72e95a3af6f8717ec3d7b58972aeeb50dfca", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/79391e19d9b72206d5e63a0c56b21e39c766c44614d42e03de49cc95e87e98b35a9496a7b6a1ad085d5893135efa75c98c33e9d86f71832dea54d863e4767ef3", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/870d1a4b20c3ec58edd8881b32e86b48cec5be75fffd52d1b6506c2c851a64064efc123c074def3c249b6d089943f6935b4b51817cd765ef1b08a0d9f6a5cc48", "g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/0f339e2ad0937af18d4d5a08133ec79405c4dda401c6c51dabba21ac933b1e06966559eb2602033a56f1a2f4a491a43b6510d725ed7c589f0cfafc59742277c6"}' ========= master_lag: 0.02 ========= ========= Finished set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-10-23 03:52:03.096825) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-10-23 03:52:03.097215) ========= 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=df17445c3590ff7897617a0e00000225-1508755261.676070-755970385 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.004614 ========= master_lag: 0.33 ========= ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-10-23 03:52:03.436572) ========= ========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2017-10-23 03:52:03.436912) ========= ========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2017-10-23 03:52:03.437585) ========= ========= Total master_lag: 0.58 =========