builder: mozilla-central_ubuntu64_hw_test-g4-e10s-pgo slave: talos-linux64-ix-058 starttime: 1510262133.68 results: success (0) revision: 6409f04e33d62148f988f567d1ef90a6f7b0ac9d ========= Started set props: master (results: 0, elapsed: 0 secs) (at 2017-11-09 13:15:33.678825) ========= master: http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/ ========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2017-11-09 13:15:33.679233) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-11-09 13:15:33.679510) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-11-09 13:15:33.696375) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-11-09 13:15:33.696698) ========= 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=0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False --2017-11-09 13:15:33-- https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py Resolving hg.mozilla.org (hg.mozilla.org)... 63.245.215.102, 63.245.215.25 Connecting to hg.mozilla.org (hg.mozilla.org)|63.245.215.102|:443... connected. HTTP request sent, awaiting response... 200 Script output follows Length: 12179 (12K) [text/x-python] Saving to: `archiver_client.py' 0K .......... . 100% 74.7K=0.2s 2017-11-09 13:15:33 (74.7 KB/s) - `archiver_client.py' saved [12179/12179] program finished with exit code 0 elapsedTime=0.361882 ========= master_lag: 0.05 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-11-09 13:15:34.105787) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-11-09 13:15:34.106122) ========= 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=0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.017687 ========= master_lag: 0.03 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-11-09 13:15:34.155195) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-11-09 13:15:34.155531) ========= bash -c 'python archiver_client.py mozharness --repo mozilla-central --rev 6409f04e33d62148f988f567d1ef90a6f7b0ac9d --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 6409f04e33d62148f988f567d1ef90a6f7b0ac9d --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=0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 2017-11-09 13:15:34,084 truncating revision to first 12 chars 2017-11-09 13:15:34,084 Setting DEBUG logging. 2017-11-09 13:15:34,084 attempt 1/10 2017-11-09 13:15:34,084 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/mozilla-central/6409f04e33d6?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness 2017-11-09 13:15:34,335 unpacking tar archive at: mozilla-central-6409f04e33d6/testing/mozharness/ program finished with exit code 0 elapsedTime=0.841674 ========= master_lag: 0.02 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-11-09 13:15:35.016361) ========= ========= Started set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-11-09 13:15:35.016669) ========= script_repo_revision: 6409f04e33d62148f988f567d1ef90a6f7b0ac9d ========= Finished set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-11-09 13:15:35.017033) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-11-09 13:15:35.017308) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-11-09 13:15:35.032037) ========= ========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 12 mins, 46 secs) (at 2017-11-09 13:15:35.032391) ========= /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=0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 13:15:35 INFO - MultiFileLogger online at 20171109 13:15:35 in /builds/slave/test 13:15:35 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 13:15:35 INFO - Dumping config to /builds/slave/test/logs/localconfig.json. 13:15:35 INFO - {'append_to_log': False, 13:15:35 INFO - 'base_work_dir': '/builds/slave/test', 13:15:35 INFO - 'blob_upload_branch': 'Firefox', 13:15:35 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt', 13:15:35 INFO - 'branch': 'Firefox', 13:15:35 INFO - 'buildbot_json_path': 'buildprops.json', 13:15:35 INFO - 'code_coverage': False, 13:15:35 INFO - 'config_files': ('talos/linux_config.py',), 13:15:35 INFO - 'default_actions': ('clobber', 13:15:35 INFO - 'read-buildbot-config', 13:15:35 INFO - 'download-and-extract', 13:15:35 INFO - 'populate-webroot', 13:15:35 INFO - 'create-virtualenv', 13:15:35 INFO - 'install', 13:15:35 INFO - 'setup-mitmproxy', 13:15:35 INFO - 'run-tests'), 13:15:35 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 13:15:35 INFO - 'disable_ccov_upload': False, 13:15:35 INFO - 'disable_stylo': False, 13:15:35 INFO - 'download_minidump_stackwalk': True, 13:15:35 INFO - 'download_symbols': 'ondemand', 13:15:35 INFO - 'e10s': False, 13:15:35 INFO - 'enable_stylo': False, 13:15:35 INFO - 'enable_webrender': False, 13:15:35 INFO - 'exes': {'tooltool.py': '/tools/tooltool.py'}, 13:15:35 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 13:15:35 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 13:15:35 INFO - 'gecko_profile': False, 13:15:35 INFO - 'gecko_profile_interval': 0, 13:15:35 INFO - 'installer_path': 'installer.exe', 13:15:35 INFO - 'jsd_code_coverage': False, 13:15:35 INFO - 'log_level': 'info', 13:15:35 INFO - 'log_name': 'talos', 13:15:35 INFO - 'log_to_console': True, 13:15:35 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk', 13:15:35 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest', 13:15:35 INFO - 'opt_config_files': (), 13:15:35 INFO - 'pip_index': False, 13:15:35 INFO - 'suite': 'g4-e10s', 13:15:35 INFO - 'system_bits': '32', 13:15:35 INFO - 'talos_extra_options': ('--webServer', 'localhost'), 13:15:35 INFO - 'title': 'talos-linux64-ix-058', 13:15:35 INFO - 'tooltool_cache': '/builds/tooltool_cache', 13:15:35 INFO - 'use_talos_json': True, 13:15:35 INFO - 'verify': 'False', 13:15:35 INFO - 'virtualenv_path': '/builds/slave/test/build/venv', 13:15:35 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 13:15:35 INFO - 'work_dir': 'build'} 13:15:35 INFO - [mozharness: 2017-11-09 21:15:35.180016Z] Running clobber step. 13:15:35 INFO - Running pre-action listener: _resource_record_pre_action 13:15:35 INFO - Running main action method: clobber 13:15:35 INFO - rmtree: /builds/slave/test/build 13:15:35 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1 13:15:36 INFO - Running post-action listener: _resource_record_post_action 13:15:36 INFO - [mozharness: 2017-11-09 21:15:36.190500Z] Finished clobber step (success) 13:15:36 INFO - [mozharness: 2017-11-09 21:15:36.190597Z] Running read-buildbot-config step. 13:15:36 INFO - Running pre-action listener: _resource_record_pre_action 13:15:36 INFO - Running main action method: read_buildbot_config 13:15:36 INFO - Using buildbot properties: 13:15:36 INFO - { 13:15:36 INFO - "project": "", 13:15:36 INFO - "product": "firefox", 13:15:36 INFO - "who": "ffxbld@noreply.mozilla.org", 13:15:36 INFO - "installer_path": "public/build/target.tar.bz2", 13:15:36 INFO - "builddir": "mozilla-central_ubuntu64_hw_test-g4-e10s", 13:15:36 INFO - "repository": "https://hg.mozilla.org/mozilla-central", 13:15:36 INFO - "buildername": "Ubuntu HW 12.04 x64 mozilla-central pgo talos g4-e10s", 13:15:36 INFO - "stage_platform": "linux64-pgo", 13:15:36 INFO - "basedir": "/builds/slave/test", 13:15:36 INFO - "buildnumber": 270, 13:15:36 INFO - "platform": "ubuntu64_hw", 13:15:36 INFO - "master": "http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/", 13:15:36 INFO - "slavebuilddir": "test", 13:15:36 INFO - "taskId": "Il5V3dR0T5ixTG-CE6QCYg", 13:15:36 INFO - "branch": "mozilla-central", 13:15:36 INFO - "script_repo_revision": "production", 13:15:36 INFO - "revision": "6409f04e33d62148f988f567d1ef90a6f7b0ac9d", 13:15:36 INFO - "slavename": "talos-linux64-ix-058", 13:15:36 INFO - "repo_path": "mozilla-central" 13:15:36 INFO - } 13:15:36 INFO - Finding installer, test and symbols from parent task. 13:15:36 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/Il5V3dR0T5ixTG-CE6QCYg'}, attempt #1 13:15:36 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/Il5V3dR0T5ixTG-CE6QCYg'}, attempt #1 13:15:37 INFO - Task dependencies: CuZ7j_4HT9Cb5o1Dot5Z3w 13:15:37 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/CuZ7j_4HT9Cb5o1Dot5Z3w'}, attempt #1 13:15:37 INFO - Set installer_url: https://queue.taskcluster.net/v1/task/CuZ7j_4HT9Cb5o1Dot5Z3w/artifacts/public/build/target.tar.bz2 13:15:37 INFO - Set test_packages_url: https://queue.taskcluster.net/v1/task/CuZ7j_4HT9Cb5o1Dot5Z3w/artifacts/public/build/target.test_packages.json 13:15:37 INFO - Set symbols_url: https://queue.taskcluster.net/v1/task/CuZ7j_4HT9Cb5o1Dot5Z3w/artifacts/public/build/target.crashreporter-symbols.zip 13:15:37 INFO - Running post-action listener: _resource_record_post_action 13:15:37 INFO - [mozharness: 2017-11-09 21:15:37.522045Z] Finished read-buildbot-config step (success) 13:15:37 INFO - [mozharness: 2017-11-09 21:15:37.522263Z] Running download-and-extract step. 13:15:37 INFO - Running pre-action listener: _resource_record_pre_action 13:15:37 INFO - Running main action method: download_and_extract 13:15:37 INFO - mkdir: /builds/slave/test/build/tests 13:15:37 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')]} 13:15:37 INFO - trying https://queue.taskcluster.net/v1/task/CuZ7j_4HT9Cb5o1Dot5Z3w/artifacts/public/build/target.test_packages.json 13:15:37 INFO - Downloading https://queue.taskcluster.net/v1/task/CuZ7j_4HT9Cb5o1Dot5Z3w/artifacts/public/build/target.test_packages.json to /builds/slave/test/build/target.test_packages.json 13:15:37 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/CuZ7j_4HT9Cb5o1Dot5Z3w/artifacts/public/build/target.test_packages.json', 'file_name': '/builds/slave/test/build/target.test_packages.json'}, attempt #1 13:15:38 INFO - Downloaded 989 bytes. 13:15:38 INFO - Reading from file /builds/slave/test/build/target.test_packages.json 13:15:38 INFO - Using the following test package requirements: 13:15:38 INFO - {u'awsy': [u'target.common.tests.zip', u'target.awsy.tests.zip'], 13:15:38 INFO - u'common': [u'target.common.tests.zip'], 13:15:38 INFO - u'cppunittest': [u'target.common.tests.zip', u'target.cppunittest.tests.zip'], 13:15:38 INFO - u'gtest': [u'target.common.tests.zip', u'target.gtest.tests.zip'], 13:15:38 INFO - u'jittest': [u'target.common.tests.zip', u'target.jsshell.zip'], 13:15:38 INFO - u'mochitest': [u'target.common.tests.zip', u'target.mochitest.tests.zip'], 13:15:38 INFO - u'mozbase': [u'target.common.tests.zip'], 13:15:38 INFO - u'reftest': [u'target.common.tests.zip', u'target.reftest.tests.zip'], 13:15:38 INFO - u'talos': [u'target.common.tests.zip', u'target.talos.tests.zip'], 13:15:38 INFO - u'web-platform': [u'target.common.tests.zip', 13:15:38 INFO - u'target.web-platform.tests.tar.gz'], 13:15:38 INFO - u'xpcshell': [u'target.common.tests.zip', u'target.xpcshell.tests.zip']} 13:15:38 INFO - Downloading packages: [u'target.common.tests.zip', u'target.talos.tests.zip'] for test suite categories: ['common', 'talos'] 13:15:38 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/CuZ7j_4HT9Cb5o1Dot5Z3w/artifacts/public/build/target.common.tests.zip 13:15:38 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/CuZ7j_4HT9Cb5o1Dot5Z3w/artifacts/public/build/target.common.tests.zip'}, attempt #1 13:15:38 INFO - Fetch https://queue.taskcluster.net/v1/task/CuZ7j_4HT9Cb5o1Dot5Z3w/artifacts/public/build/target.common.tests.zip into memory 13:15:39 INFO - Content-Length response header: 58647975 13:15:39 INFO - Bytes received: 58647975 13:15:50 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/CuZ7j_4HT9Cb5o1Dot5Z3w/artifacts/public/build/target.talos.tests.zip 13:15:50 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/CuZ7j_4HT9Cb5o1Dot5Z3w/artifacts/public/build/target.talos.tests.zip'}, attempt #1 13:15:50 INFO - Fetch https://queue.taskcluster.net/v1/task/CuZ7j_4HT9Cb5o1Dot5Z3w/artifacts/public/build/target.talos.tests.zip into memory 13:15:51 INFO - Content-Length response header: 18771918 13:15:51 INFO - Bytes received: 18771918 13:15:51 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')]} 13:15:51 INFO - trying https://queue.taskcluster.net/v1/task/CuZ7j_4HT9Cb5o1Dot5Z3w/artifacts/public/build/target.tar.bz2 13:15:51 INFO - Downloading https://queue.taskcluster.net/v1/task/CuZ7j_4HT9Cb5o1Dot5Z3w/artifacts/public/build/target.tar.bz2 to /builds/slave/test/build/target.tar.bz2 13:15:51 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/CuZ7j_4HT9Cb5o1Dot5Z3w/artifacts/public/build/target.tar.bz2', 'file_name': '/builds/slave/test/build/target.tar.bz2'}, attempt #1 13:15:52 INFO - Downloaded 63204074 bytes. 13:15:52 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/CuZ7j_4HT9Cb5o1Dot5Z3w/artifacts/public/build/target.tar.bz2 13:15:52 INFO - mkdir: /builds/slave/test/properties 13:15:52 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url 13:15:52 INFO - Writing to file /builds/slave/test/properties/build_url 13:15:52 INFO - Contents: 13:15:52 INFO - build_url:https://queue.taskcluster.net/v1/task/CuZ7j_4HT9Cb5o1Dot5Z3w/artifacts/public/build/target.tar.bz2 13:15:52 INFO - Running post-action listener: _resource_record_post_action 13:15:52 INFO - Running post-action listener: find_tests_for_verification 13:15:52 INFO - Running post-action listener: set_extra_try_arguments 13:15:52 INFO - [mozharness: 2017-11-09 21:15:52.834960Z] Finished download-and-extract step (success) 13:15:52 INFO - [mozharness: 2017-11-09 21:15:52.835056Z] Running populate-webroot step. 13:15:52 INFO - Running pre-action listener: _resource_record_pre_action 13:15:52 INFO - Running main action method: populate_webroot 13:15:52 INFO - {'suites': {'chromez-e10s': {'tests': ['tresize', 'tcanvasmark']}, 13:15:52 INFO - 'chromez-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:15:52 INFO - 'tests': ['tresize', 13:15:52 INFO - 'tcanvasmark']}, 13:15:52 INFO - 'dromaeojs-e10s': {'tests': ['dromaeo_css', 'kraken']}, 13:15:52 INFO - 'dromaeojs-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:15:52 INFO - 'tests': ['dromaeo_css', 13:15:52 INFO - 'kraken']}, 13:15:52 INFO - 'g1-e10s': {'pagesets_name': 'tp5n.zip', 13:15:52 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 13:15:52 INFO - 'g1-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 13:15:52 INFO - 'talos_options': ['--disable-stylo'], 13:15:52 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 13:15:52 INFO - 'g2-e10s': {'pagesets_name': 'tp5n.zip', 13:15:52 INFO - 'tests': ['damp', 'tps']}, 13:15:52 INFO - 'g2-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 13:15:52 INFO - 'talos_options': ['--disable-stylo'], 13:15:52 INFO - 'tests': ['damp', 'tps']}, 13:15:52 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']}, 13:15:52 INFO - 'g3-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:15:52 INFO - 'tests': ['dromaeo_dom']}, 13:15:52 INFO - 'g4-e10s': {'tests': ['basic_compositor_video', 13:15:52 INFO - 'glvideo', 13:15:52 INFO - 'displaylist_mutate']}, 13:15:52 INFO - 'g4-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:15:52 INFO - 'tests': ['basic_compositor_video', 13:15:52 INFO - 'glvideo']}, 13:15:52 INFO - 'g5-e10s': {'pagesets_name': 'tp5n.zip', 13:15:52 INFO - 'tests': ['ts_paint_webext', 'tp5o_webext']}, 13:15:52 INFO - 'g5-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 13:15:52 INFO - 'talos_options': ['--disable-stylo'], 13:15:52 INFO - 'tests': ['ts_paint_webext', 13:15:52 INFO - 'tp5o_webext']}, 13:15:52 INFO - 'h1-e10s': {'tests': ['ts_paint_heavy']}, 13:15:52 INFO - 'h2-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 13:15:52 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 13:15:52 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 13:15:52 INFO - 'talos_options': ['--mitmproxy', 13:15:52 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 13:15:52 INFO - '--firstNonBlankPaint'], 13:15:52 INFO - 'tests': ['tp6_google_heavy', 13:15:52 INFO - 'tp6_youtube_heavy', 13:15:52 INFO - 'tp6_amazon_heavy', 13:15:52 INFO - 'tp6_facebook_heavy']}, 13:15:52 INFO - 'other-e10s': {'tests': ['a11yr', 13:15:52 INFO - 'ts_paint', 13:15:52 INFO - 'tpaint', 13:15:52 INFO - 'sessionrestore', 13:15:52 INFO - 'sessionrestore_many_windows', 13:15:52 INFO - 'sessionrestore_no_auto_restore', 13:15:52 INFO - 'tabpaint', 13:15:52 INFO - 'cpstartup']}, 13:15:52 INFO - 'other-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:15:52 INFO - 'tests': ['a11yr', 13:15:52 INFO - 'ts_paint', 13:15:52 INFO - 'tpaint', 13:15:52 INFO - 'sessionrestore', 13:15:52 INFO - 'sessionrestore_many_windows', 13:15:52 INFO - 'sessionrestore_no_auto_restore', 13:15:52 INFO - 'tabpaint', 13:15:52 INFO - 'cpstartup']}, 13:15:52 INFO - 'perf-reftest-e10s': {'tests': ['perf_reftest']}, 13:15:52 INFO - 'perf-reftest-singletons-e10s': {'tests': ['perf_reftest_singletons']}, 13:15:52 INFO - 'perf-reftest-singletons-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:15:52 INFO - 'tests': ['perf_reftest_singletons']}, 13:15:52 INFO - 'perf-reftest-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:15:52 INFO - 'tests': ['perf_reftest']}, 13:15:52 INFO - 'speedometer-e10s': {'tests': ['speedometer']}, 13:15:52 INFO - 'speedometer-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:15:52 INFO - 'tests': ['speedometer']}, 13:15:52 INFO - 'svgr-e10s': {'tests': ['tsvgx', 13:15:52 INFO - 'tsvgr_opacity', 13:15:52 INFO - 'tart', 13:15:52 INFO - 'tscrollx', 13:15:52 INFO - 'tsvg_static']}, 13:15:52 INFO - 'svgr-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:15:52 INFO - 'tests': ['tsvgx', 13:15:52 INFO - 'tsvgr_opacity', 13:15:52 INFO - 'tart', 13:15:52 INFO - 'tscrollx', 13:15:52 INFO - 'tsvg_static']}, 13:15:52 INFO - 'tp5o-e10s': {'pagesets_name': 'tp5n.zip', 'tests': ['tp5o']}, 13:15:52 INFO - 'tp5o-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 13:15:52 INFO - 'talos_options': ['--disable-stylo'], 13:15:52 INFO - 'tests': ['tp5o']}, 13:15:52 INFO - 'tp6-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 13:15:52 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 13:15:52 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 13:15:52 INFO - 'talos_options': ['--mitmproxy', 13:15:52 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 13:15:52 INFO - '--firstNonBlankPaint'], 13:15:52 INFO - 'tests': ['tp6_google', 13:15:52 INFO - 'tp6_youtube', 13:15:52 INFO - 'tp6_amazon', 13:15:52 INFO - 'tp6_facebook']}, 13:15:52 INFO - 'tp6-stylo-disabled-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 13:15:52 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 13:15:52 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 13:15:52 INFO - 'talos_options': ['--disable-stylo', 13:15:52 INFO - '--mitmproxy', 13:15:52 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 13:15:52 INFO - '--firstNonBlankPaint'], 13:15:52 INFO - 'tests': ['tp6_google', 13:15:52 INFO - 'tp6_youtube', 13:15:52 INFO - 'tp6_amazon', 13:15:52 INFO - 'tp6_facebook']}, 13:15:52 INFO - 'tp6-stylo-threads-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 13:15:52 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 13:15:52 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 13:15:52 INFO - 'talos_options': ['--stylo-threads=1', 13:15:52 INFO - '--mitmproxy', 13:15:52 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 13:15:52 INFO - '--firstNonBlankPaint'], 13:15:52 INFO - 'tests': ['tp6_google', 13:15:52 INFO - 'tp6_youtube', 13:15:52 INFO - 'tp6_amazon', 13:15:52 INFO - 'tp6_facebook']}, 13:15:52 INFO - 'xperf-e10s': {'pagesets_name': 'tp5n.zip', 13:15:52 INFO - 'talos_options': ['--xperf_path', 13:15:52 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 13:15:52 INFO - 'tests': ['tp5n']}, 13:15:52 INFO - 'xperf-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 13:15:52 INFO - 'talos_options': ['--disable-stylo', 13:15:52 INFO - '--xperf_path', 13:15:52 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 13:15:52 INFO - 'tests': ['tp5n']}}} 13:15:52 INFO - Running post-action listener: _resource_record_post_action 13:15:52 INFO - [mozharness: 2017-11-09 21:15:52.853580Z] Finished populate-webroot step (success) 13:15:52 INFO - [mozharness: 2017-11-09 21:15:52.853673Z] Running create-virtualenv step. 13:15:52 INFO - Running pre-action listener: _resource_record_pre_action 13:15:52 INFO - Running main action method: create_virtualenv 13:15:52 INFO - Creating virtualenv /builds/slave/test/build/venv 13:15:52 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 13:15:52 INFO - Copy/paste: /tools/buildbot/bin/python /builds/slave/test/scripts/external_tools/virtualenv/virtualenv.py --always-copy /builds/slave/test/build/venv 13:15:52 INFO - Using partial env: {'VIRTUALENV_NO_DOWNLOAD': '1'} 13:15:54 INFO - Using real prefix '/usr' 13:15:54 INFO - New python executable in /builds/slave/test/build/venv/bin/python 13:15:54 INFO - Overwriting /builds/slave/test/build/venv/lib/python2.7/distutils/__init__.py with new content 13:15:56 INFO - Installing setuptools, pip, wheel...done. 13:15:56 INFO - Return code: 0 13:15:56 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv 13:15:56 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')]} 13:15:56 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:15:56 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')]} 13:15:56 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:15:56 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 0x17f22d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x19cca80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1b6bd70>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b6f070>, '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 0x1b70080>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b6a2a0>, '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': '0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215', '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 13:15:56 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 13:15:56 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 13:15:56 INFO - Using env: {'DISPLAY': ':0', 13:15:56 INFO - 'HOME': '/home/cltbld', 13:15:56 INFO - 'LANG': 'en_US.UTF-8', 13:15:56 INFO - 'LANGUAGE': 'en_US:en', 13:15:56 INFO - 'LOGNAME': 'cltbld', 13:15:56 INFO - 'MAIL': '/var/mail/cltbld', 13:15:56 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:15:56 INFO - 'MOZ_NO_REMOTE': '1', 13:15:56 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:15:56 INFO - 'NO_EM_RESTART': '1', 13:15:56 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:15:56 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:15:56 INFO - 'PWD': '/builds/slave/test', 13:15:56 INFO - 'SHELL': '/bin/bash', 13:15:56 INFO - 'SHLVL': '1', 13:15:56 INFO - 'TERM': 'linux', 13:15:56 INFO - 'TMOUT': '86400', 13:15:56 INFO - 'USER': 'cltbld', 13:15:56 INFO - 'XDG_SESSION_COOKIE': '0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215', 13:15:56 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:15:56 INFO - '_': '/tools/buildbot/bin/python'} 13:15:56 INFO - Ignoring indexes: https://pypi.python.org/simple 13:15:56 INFO - Requirement already satisfied (use --upgrade to upgrade): pip>=1.5 in ./venv/lib/python2.7/site-packages 13:15:56 INFO - Return code: 0 13:15:56 INFO - Installing psutil>=3.1.1 into virtualenv /builds/slave/test/build/venv 13:15:56 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')]} 13:15:56 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:15:56 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')]} 13:15:56 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:15:56 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 0x17f22d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x19cca80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1b6bd70>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b6f070>, '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 0x1b70080>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b6a2a0>, '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': '0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215', '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 13:15:56 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 13:15:56 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 13:15:56 INFO - Using env: {'DISPLAY': ':0', 13:15:56 INFO - 'HOME': '/home/cltbld', 13:15:56 INFO - 'LANG': 'en_US.UTF-8', 13:15:56 INFO - 'LANGUAGE': 'en_US:en', 13:15:56 INFO - 'LOGNAME': 'cltbld', 13:15:56 INFO - 'MAIL': '/var/mail/cltbld', 13:15:56 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:15:56 INFO - 'MOZ_NO_REMOTE': '1', 13:15:56 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:15:56 INFO - 'NO_EM_RESTART': '1', 13:15:56 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:15:56 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:15:56 INFO - 'PWD': '/builds/slave/test', 13:15:56 INFO - 'SHELL': '/bin/bash', 13:15:56 INFO - 'SHLVL': '1', 13:15:56 INFO - 'TERM': 'linux', 13:15:56 INFO - 'TMOUT': '86400', 13:15:56 INFO - 'USER': 'cltbld', 13:15:56 INFO - 'XDG_SESSION_COOKIE': '0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215', 13:15:56 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:15:56 INFO - '_': '/tools/buildbot/bin/python'} 13:15:57 INFO - Ignoring indexes: https://pypi.python.org/simple 13:15:57 INFO - Collecting psutil>=3.1.1 13:15:58 INFO - Installing collected packages: psutil 13:15:58 INFO - Successfully installed psutil-3.1.1 13:15:58 INFO - Return code: 0 13:15:58 INFO - Installing mozsystemmonitor==0.3 into virtualenv /builds/slave/test/build/venv 13:15:58 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')]} 13:15:58 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:15:58 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')]} 13:15:58 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:15:58 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 0x17f22d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x19cca80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1b6bd70>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b6f070>, '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 0x1b70080>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b6a2a0>, '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': '0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215', '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 13:15:58 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 13:15:58 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 13:15:58 INFO - Using env: {'DISPLAY': ':0', 13:15:58 INFO - 'HOME': '/home/cltbld', 13:15:58 INFO - 'LANG': 'en_US.UTF-8', 13:15:58 INFO - 'LANGUAGE': 'en_US:en', 13:15:58 INFO - 'LOGNAME': 'cltbld', 13:15:58 INFO - 'MAIL': '/var/mail/cltbld', 13:15:58 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:15:58 INFO - 'MOZ_NO_REMOTE': '1', 13:15:58 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:15:58 INFO - 'NO_EM_RESTART': '1', 13:15:58 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:15:58 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:15:58 INFO - 'PWD': '/builds/slave/test', 13:15:58 INFO - 'SHELL': '/bin/bash', 13:15:58 INFO - 'SHLVL': '1', 13:15:58 INFO - 'TERM': 'linux', 13:15:58 INFO - 'TMOUT': '86400', 13:15:58 INFO - 'USER': 'cltbld', 13:15:58 INFO - 'XDG_SESSION_COOKIE': '0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215', 13:15:58 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:15:58 INFO - '_': '/tools/buildbot/bin/python'} 13:15:59 INFO - Ignoring indexes: https://pypi.python.org/simple 13:15:59 INFO - Collecting mozsystemmonitor==0.3 13:16:00 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.3) 13:16:00 INFO - Installing collected packages: mozsystemmonitor 13:16:00 INFO - Successfully installed mozsystemmonitor-0.3 13:16:00 INFO - Return code: 0 13:16:00 INFO - Installing jsonschema==2.5.1 into virtualenv /builds/slave/test/build/venv 13:16:00 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:16:00 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:16:00 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:16:00 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:16:00 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 0x17f22d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x19cca80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1b6bd70>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b6f070>, '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 0x1b70080>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b6a2a0>, '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': '0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215', '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 13:16:00 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 13:16:00 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 13:16:00 INFO - Using env: {'DISPLAY': ':0', 13:16:00 INFO - 'HOME': '/home/cltbld', 13:16:00 INFO - 'LANG': 'en_US.UTF-8', 13:16:00 INFO - 'LANGUAGE': 'en_US:en', 13:16:00 INFO - 'LOGNAME': 'cltbld', 13:16:00 INFO - 'MAIL': '/var/mail/cltbld', 13:16:00 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:16:00 INFO - 'MOZ_NO_REMOTE': '1', 13:16:00 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:16:00 INFO - 'NO_EM_RESTART': '1', 13:16:00 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:16:00 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:16:00 INFO - 'PWD': '/builds/slave/test', 13:16:00 INFO - 'SHELL': '/bin/bash', 13:16:00 INFO - 'SHLVL': '1', 13:16:00 INFO - 'TERM': 'linux', 13:16:00 INFO - 'TMOUT': '86400', 13:16:00 INFO - 'USER': 'cltbld', 13:16:00 INFO - 'XDG_SESSION_COOKIE': '0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215', 13:16:00 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:16:00 INFO - '_': '/tools/buildbot/bin/python'} 13:16:00 INFO - Ignoring indexes: https://pypi.python.org/simple 13:16:00 INFO - Collecting jsonschema==2.5.1 13:16:01 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/jsonschema-2.5.1-py2.py3-none-any.whl 13:16:01 INFO - Collecting functools32; python_version == "2.7" (from jsonschema==2.5.1) 13:16:02 INFO - Installing collected packages: functools32, jsonschema 13:16:02 INFO - Successfully installed functools32-3.2.3.post2 jsonschema-2.5.1 13:16:02 INFO - Return code: 0 13:16:02 INFO - Installing functools32==3.2.3-2 into virtualenv /builds/slave/test/build/venv 13:16:02 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')]} 13:16:02 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:16:02 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')]} 13:16:02 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:16:02 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 0x17f22d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x19cca80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1b6bd70>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b6f070>, '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 0x1b70080>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b6a2a0>, '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': '0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215', '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 13:16:02 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 13:16:02 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 13:16:02 INFO - Using env: {'DISPLAY': ':0', 13:16:02 INFO - 'HOME': '/home/cltbld', 13:16:02 INFO - 'LANG': 'en_US.UTF-8', 13:16:02 INFO - 'LANGUAGE': 'en_US:en', 13:16:02 INFO - 'LOGNAME': 'cltbld', 13:16:02 INFO - 'MAIL': '/var/mail/cltbld', 13:16:02 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:16:02 INFO - 'MOZ_NO_REMOTE': '1', 13:16:02 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:16:02 INFO - 'NO_EM_RESTART': '1', 13:16:02 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:16:02 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:16:02 INFO - 'PWD': '/builds/slave/test', 13:16:02 INFO - 'SHELL': '/bin/bash', 13:16:02 INFO - 'SHLVL': '1', 13:16:02 INFO - 'TERM': 'linux', 13:16:02 INFO - 'TMOUT': '86400', 13:16:02 INFO - 'USER': 'cltbld', 13:16:02 INFO - 'XDG_SESSION_COOKIE': '0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215', 13:16:02 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:16:02 INFO - '_': '/tools/buildbot/bin/python'} 13:16:03 INFO - Ignoring indexes: https://pypi.python.org/simple 13:16:03 INFO - Requirement already satisfied (use --upgrade to upgrade): functools32==3.2.3-2 in ./venv/lib/python2.7/site-packages 13:16:03 INFO - Return code: 0 13:16:03 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv 13:16:03 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')]} 13:16:03 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:16:03 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')]} 13:16:03 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:16:03 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 0x17f22d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x19cca80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1b6bd70>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b6f070>, '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 0x1b70080>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b6a2a0>, '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': '0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215', '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 13:16:03 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 13:16:03 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 13:16:03 INFO - Using env: {'DISPLAY': ':0', 13:16:03 INFO - 'HOME': '/home/cltbld', 13:16:03 INFO - 'LANG': 'en_US.UTF-8', 13:16:03 INFO - 'LANGUAGE': 'en_US:en', 13:16:03 INFO - 'LOGNAME': 'cltbld', 13:16:03 INFO - 'MAIL': '/var/mail/cltbld', 13:16:03 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:16:03 INFO - 'MOZ_NO_REMOTE': '1', 13:16:03 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:16:03 INFO - 'NO_EM_RESTART': '1', 13:16:03 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:16:03 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:16:03 INFO - 'PWD': '/builds/slave/test', 13:16:03 INFO - 'SHELL': '/bin/bash', 13:16:03 INFO - 'SHLVL': '1', 13:16:03 INFO - 'TERM': 'linux', 13:16:03 INFO - 'TMOUT': '86400', 13:16:03 INFO - 'USER': 'cltbld', 13:16:03 INFO - 'XDG_SESSION_COOKIE': '0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215', 13:16:03 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:16:03 INFO - '_': '/tools/buildbot/bin/python'} 13:16:03 INFO - Ignoring indexes: https://pypi.python.org/simple 13:16:03 INFO - Collecting blobuploader==1.2.4 13:16:04 INFO - Collecting requests==1.2.3. (from blobuploader==1.2.4) 13:16:06 INFO - Collecting docopt==0.6.1 (from blobuploader==1.2.4) 13:16:07 INFO - Installing collected packages: requests, docopt, blobuploader 13:16:07 INFO - Successfully installed blobuploader-1.2.4 docopt-0.6.1 requests-1.2.3 13:16:07 INFO - Return code: 0 13:16:07 INFO - Installing None into virtualenv /builds/slave/test/build/venv 13:16:07 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:16:07 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:16:07 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:16:07 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:16:07 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 0x17f22d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x19cca80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1b6bd70>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b6f070>, '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 0x1b70080>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b6a2a0>, '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': '0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215', '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 13:16:07 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 13:16:07 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 13:16:07 INFO - Using env: {'DISPLAY': ':0', 13:16:07 INFO - 'HOME': '/home/cltbld', 13:16:07 INFO - 'LANG': 'en_US.UTF-8', 13:16:07 INFO - 'LANGUAGE': 'en_US:en', 13:16:07 INFO - 'LOGNAME': 'cltbld', 13:16:07 INFO - 'MAIL': '/var/mail/cltbld', 13:16:07 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:16:07 INFO - 'MOZ_NO_REMOTE': '1', 13:16:07 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:16:07 INFO - 'NO_EM_RESTART': '1', 13:16:07 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:16:07 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:16:07 INFO - 'PWD': '/builds/slave/test', 13:16:07 INFO - 'SHELL': '/bin/bash', 13:16:07 INFO - 'SHLVL': '1', 13:16:07 INFO - 'TERM': 'linux', 13:16:07 INFO - 'TMOUT': '86400', 13:16:07 INFO - 'USER': 'cltbld', 13:16:07 INFO - 'XDG_SESSION_COOKIE': '0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215', 13:16:07 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:16:07 INFO - '_': '/tools/buildbot/bin/python'} 13:16:08 INFO - Ignoring indexes: https://pypi.python.org/simple 13:16:08 INFO - Processing /builds/slave/test/build/tests/mozbase/manifestparser 13:16:08 INFO - Processing /builds/slave/test/build/tests/mozbase/mozcrash 13:16:08 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdebug 13:16:08 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdevice 13:16:08 INFO - Processing /builds/slave/test/build/tests/mozbase/mozfile 13:16:09 INFO - Processing /builds/slave/test/build/tests/mozbase/mozhttpd 13:16:09 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinfo 13:16:09 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinstall 13:16:09 INFO - Processing /builds/slave/test/build/tests/mozbase/mozleak 13:16:09 INFO - Processing /builds/slave/test/build/tests/mozbase/mozlog 13:16:10 INFO - Processing /builds/slave/test/build/tests/mozbase/moznetwork 13:16:10 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprocess 13:16:10 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprofile 13:16:10 INFO - Processing /builds/slave/test/build/tests/mozbase/mozrunner 13:16:10 INFO - Processing /builds/slave/test/build/tests/mozbase/mozscreenshot 13:16:10 INFO - Processing /builds/slave/test/build/tests/mozbase/moztest 13:16:11 INFO - Processing /builds/slave/test/build/tests/mozbase/mozversion 13:16:11 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion 13:16:11 INFO - Running setup.py install for manifestparser: started 13:16:11 INFO - Running setup.py install for manifestparser: finished with status 'done' 13:16:11 INFO - Running setup.py install for mozcrash: started 13:16:11 INFO - Running setup.py install for mozcrash: finished with status 'done' 13:16:11 INFO - Running setup.py install for mozdebug: started 13:16:12 INFO - Running setup.py install for mozdebug: finished with status 'done' 13:16:12 INFO - Running setup.py install for mozdevice: started 13:16:12 INFO - Running setup.py install for mozdevice: finished with status 'done' 13:16:12 INFO - Running setup.py install for mozfile: started 13:16:12 INFO - Running setup.py install for mozfile: finished with status 'done' 13:16:12 INFO - Running setup.py install for mozhttpd: started 13:16:12 INFO - Running setup.py install for mozhttpd: finished with status 'done' 13:16:12 INFO - Running setup.py install for mozinfo: started 13:16:12 INFO - Running setup.py install for mozinfo: finished with status 'done' 13:16:12 INFO - Running setup.py install for mozInstall: started 13:16:13 INFO - Running setup.py install for mozInstall: finished with status 'done' 13:16:13 INFO - Running setup.py install for mozleak: started 13:16:13 INFO - Running setup.py install for mozleak: finished with status 'done' 13:16:13 INFO - Running setup.py install for mozlog: started 13:16:13 INFO - Running setup.py install for mozlog: finished with status 'done' 13:16:13 INFO - Running setup.py install for moznetwork: started 13:16:13 INFO - Running setup.py install for moznetwork: finished with status 'done' 13:16:13 INFO - Running setup.py install for mozprocess: started 13:16:13 INFO - Running setup.py install for mozprocess: finished with status 'done' 13:16:13 INFO - Running setup.py install for mozprofile: started 13:16:14 INFO - Running setup.py install for mozprofile: finished with status 'done' 13:16:14 INFO - Running setup.py install for mozrunner: started 13:16:14 INFO - Running setup.py install for mozrunner: finished with status 'done' 13:16:14 INFO - Running setup.py install for mozscreenshot: started 13:16:14 INFO - Running setup.py install for mozscreenshot: finished with status 'done' 13:16:14 INFO - Running setup.py install for moztest: started 13:16:14 INFO - Running setup.py install for moztest: finished with status 'done' 13:16:14 INFO - Running setup.py install for mozversion: started 13:16:15 INFO - Running setup.py install for mozversion: finished with status 'done' 13:16:15 INFO - Successfully installed manifestparser-1.2 mozInstall-1.14 mozcrash-1.0 mozdebug-0.1 mozdevice-0.51 mozfile-1.2 mozhttpd-0.7 mozinfo-0.10 mozleak-0.1 mozlog-3.5 moznetwork-0.27 mozprocess-0.25 mozprofile-0.29 mozrunner-6.13 mozscreenshot-0.1 moztest-0.8 mozversion-1.4 13:16:15 INFO - Return code: 0 13:16:15 INFO - Installing None into virtualenv /builds/slave/test/build/venv 13:16:15 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:16:15 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:16:15 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:16:15 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:16:15 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 0x17f22d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x19cca80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1b6bd70>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b6f070>, '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 0x1b70080>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b6a2a0>, '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': '0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215', '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 13:16:15 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 13:16:15 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 13:16:15 INFO - Using env: {'DISPLAY': ':0', 13:16:15 INFO - 'HOME': '/home/cltbld', 13:16:15 INFO - 'LANG': 'en_US.UTF-8', 13:16:15 INFO - 'LANGUAGE': 'en_US:en', 13:16:15 INFO - 'LOGNAME': 'cltbld', 13:16:15 INFO - 'MAIL': '/var/mail/cltbld', 13:16:15 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:16:15 INFO - 'MOZ_NO_REMOTE': '1', 13:16:15 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:16:15 INFO - 'NO_EM_RESTART': '1', 13:16:15 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:16:15 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:16:15 INFO - 'PWD': '/builds/slave/test', 13:16:15 INFO - 'SHELL': '/bin/bash', 13:16:15 INFO - 'SHLVL': '1', 13:16:15 INFO - 'TERM': 'linux', 13:16:15 INFO - 'TMOUT': '86400', 13:16:15 INFO - 'USER': 'cltbld', 13:16:15 INFO - 'XDG_SESSION_COOKIE': '0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215', 13:16:15 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:16:15 INFO - '_': '/tools/buildbot/bin/python'} 13:16:15 INFO - Ignoring indexes: https://pypi.python.org/simple 13:16:15 INFO - Processing /builds/slave/test/build/tests/mozbase/manifestparser 13:16:16 INFO - Requirement already satisfied (use --upgrade to upgrade): manifestparser==1.2 from file:///builds/slave/test/build/tests/mozbase/manifestparser in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 1)) 13:16:16 INFO - Processing /builds/slave/test/build/tests/mozbase/mozcrash 13:16:16 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)) 13:16:16 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdebug 13:16:16 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)) 13:16:16 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdevice 13:16:16 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)) 13:16:16 INFO - Processing /builds/slave/test/build/tests/mozbase/mozfile 13:16:16 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)) 13:16:16 INFO - Processing /builds/slave/test/build/tests/mozbase/mozhttpd 13:16:17 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)) 13:16:17 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinfo 13:16:17 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)) 13:16:17 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinstall 13:16:17 INFO - Requirement already satisfied (use --upgrade to upgrade): mozInstall==1.14 from file:///builds/slave/test/build/tests/mozbase/mozinstall in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 8)) 13:16:17 INFO - Processing /builds/slave/test/build/tests/mozbase/mozleak 13:16:17 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)) 13:16:17 INFO - Processing /builds/slave/test/build/tests/mozbase/mozlog 13:16:17 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)) 13:16:17 INFO - Processing /builds/slave/test/build/tests/mozbase/moznetwork 13:16:18 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)) 13:16:18 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprocess 13:16:18 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)) 13:16:18 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprofile 13:16:18 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile==0.29 from file:///builds/slave/test/build/tests/mozbase/mozprofile in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 13)) 13:16:18 INFO - Processing /builds/slave/test/build/tests/mozbase/mozrunner 13:16:18 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)) 13:16:18 INFO - Processing /builds/slave/test/build/tests/mozbase/mozscreenshot 13:16:18 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)) 13:16:18 INFO - Processing /builds/slave/test/build/tests/mozbase/moztest 13:16:19 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)) 13:16:19 INFO - Processing /builds/slave/test/build/tests/mozbase/mozversion 13:16:19 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)) 13:16:19 INFO - Collecting six>=1.10.0 (from manifestparser==1.2->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 1)) 13:16:20 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/six-1.10.0-py2.py3-none-any.whl 13:16:20 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)) 13:16:20 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)) 13:16:20 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)) 13:16:20 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)) 13:16:20 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)) 13:16:20 INFO - Requirement already satisfied (use --upgrade to upgrade): requests in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozInstall==1.14->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 8)) 13:16:20 INFO - Collecting blessings>=1.3 (from mozlog==3.5->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 13:16:21 INFO - Installing collected packages: six, blessings 13:16:21 INFO - Successfully installed blessings-1.6 six-1.10.0 13:16:21 INFO - Return code: 0 13:16:21 INFO - Done creating virtualenv /builds/slave/test/build/venv. 13:16:21 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 13:16:21 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 13:16:22 INFO - Reading from file tmpfile_stdout 13:16:22 INFO - Reading from file tmpfile_stderr 13:16:22 INFO - Current package versions: 13:16:22 INFO - blessings == 1.6 13:16:22 INFO - blobuploader == 1.2.4 13:16:22 INFO - docopt == 0.6.1 13:16:22 INFO - functools32 == 3.2.3.post2 13:16:22 INFO - jsonschema == 2.5.1 13:16:22 INFO - manifestparser == 1.2 13:16:22 INFO - mozInstall == 1.14 13:16:22 INFO - mozcrash == 1.0 13:16:22 INFO - mozdebug == 0.1 13:16:22 INFO - mozdevice == 0.51 13:16:22 INFO - mozfile == 1.2 13:16:22 INFO - mozhttpd == 0.7 13:16:22 INFO - mozinfo == 0.10 13:16:22 INFO - mozleak == 0.1 13:16:22 INFO - mozlog == 3.5 13:16:22 INFO - moznetwork == 0.27 13:16:22 INFO - mozprocess == 0.25 13:16:22 INFO - mozprofile == 0.29 13:16:22 INFO - mozrunner == 6.13 13:16:22 INFO - mozscreenshot == 0.1 13:16:22 INFO - mozsystemmonitor == 0.3 13:16:22 INFO - moztest == 0.8 13:16:22 INFO - mozversion == 1.4 13:16:22 INFO - psutil == 3.1.1 13:16:22 INFO - requests == 1.2.3 13:16:22 INFO - six == 1.10.0 13:16:22 INFO - Installing None into virtualenv /builds/slave/test/build/venv 13:16: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')]} 13:16:22 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:16: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')]} 13:16:22 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:16:22 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 0x17f22d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x19cca80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1b6bd70>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b6f070>, '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 0x1b70080>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b6a2a0>, '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': '0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215', '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 13:16:22 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 13:16:22 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 13:16:22 INFO - Using env: {'DISPLAY': ':0', 13:16:22 INFO - 'HOME': '/home/cltbld', 13:16:22 INFO - 'LANG': 'en_US.UTF-8', 13:16:22 INFO - 'LANGUAGE': 'en_US:en', 13:16:22 INFO - 'LOGNAME': 'cltbld', 13:16:22 INFO - 'MAIL': '/var/mail/cltbld', 13:16:22 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:16:22 INFO - 'MOZ_NO_REMOTE': '1', 13:16:22 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:16:22 INFO - 'NO_EM_RESTART': '1', 13:16:22 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:16:22 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:16:22 INFO - 'PWD': '/builds/slave/test', 13:16:22 INFO - 'SHELL': '/bin/bash', 13:16:22 INFO - 'SHLVL': '1', 13:16:22 INFO - 'TERM': 'linux', 13:16:22 INFO - 'TMOUT': '86400', 13:16:22 INFO - 'USER': 'cltbld', 13:16:22 INFO - 'XDG_SESSION_COOKIE': '0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215', 13:16:22 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:16:22 INFO - '_': '/tools/buildbot/bin/python'} 13:16:22 INFO - Ignoring indexes: https://pypi.python.org/simple 13:16:22 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)) 13:16:22 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)) 13:16:22 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)) 13:16:22 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)) 13:16:22 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)) 13:16:22 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)) 13:16:22 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)) 13:16:22 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)) 13:16:22 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)) 13:16:22 INFO - Collecting simplejson>=2.1.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 10)) 13:16:23 INFO - Collecting requests>=2.9.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 13:16:24 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/requests-2.18.3-py2.py3-none-any.whl (88kB) 13:16:24 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)) 13:16:24 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)) 13:16:24 INFO - Requirement already satisfied (use --upgrade to upgrade): six>=1.10.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozprofile>=0.25->-r /builds/slave/test/build/tests/talos/requirements.txt (line 8)) 13:16:24 INFO - Collecting chardet<3.1.0,>=3.0.2 (from requests>=2.9.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 13:16:25 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/chardet-3.0.4-py2.py3-none-any.whl (133kB) 13:16:25 INFO - Collecting urllib3<1.23,>=1.21.1 (from requests>=2.9.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 13:16:26 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/urllib3-1.22-py2.py3-none-any.whl (132kB) 13:16:26 INFO - Collecting certifi>=2017.4.17 (from requests>=2.9.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 13:16:28 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/certifi-2017.7.27.1-py2.py3-none-any.whl (349kB) 13:16:28 INFO - Collecting idna<2.6,>=2.5 (from requests>=2.9.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 13:16:29 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/idna-2.5-py2.py3-none-any.whl (55kB) 13:16:29 INFO - Installing collected packages: simplejson, chardet, urllib3, certifi, idna, requests 13:16:29 INFO - Found existing installation: requests 1.2.3 13:16:29 INFO - Uninstalling requests-1.2.3: 13:16:29 INFO - Successfully uninstalled requests-1.2.3 13:16:29 INFO - Successfully installed certifi-2017.7.27.1 chardet-3.0.4 idna-2.5 requests-2.18.3 simplejson-3.3.0 urllib3-1.22 13:16:29 INFO - Return code: 0 13:16:29 INFO - Installing jsonschema into virtualenv /builds/slave/test/build/venv 13:16:29 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')]} 13:16:29 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:16:29 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')]} 13:16:29 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:16:29 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 0x17f22d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x19cca80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1b6bd70>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b6f070>, '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 0x1b70080>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b6a2a0>, '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': '0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215', '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 13:16:29 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 13:16:29 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 13:16:29 INFO - Using env: {'DISPLAY': ':0', 13:16:29 INFO - 'HOME': '/home/cltbld', 13:16:29 INFO - 'LANG': 'en_US.UTF-8', 13:16:29 INFO - 'LANGUAGE': 'en_US:en', 13:16:29 INFO - 'LOGNAME': 'cltbld', 13:16:29 INFO - 'MAIL': '/var/mail/cltbld', 13:16:29 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:16:29 INFO - 'MOZ_NO_REMOTE': '1', 13:16:29 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:16:29 INFO - 'NO_EM_RESTART': '1', 13:16:29 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:16:29 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:16:29 INFO - 'PWD': '/builds/slave/test', 13:16:29 INFO - 'SHELL': '/bin/bash', 13:16:29 INFO - 'SHLVL': '1', 13:16:29 INFO - 'TERM': 'linux', 13:16:29 INFO - 'TMOUT': '86400', 13:16:29 INFO - 'USER': 'cltbld', 13:16:29 INFO - 'XDG_SESSION_COOKIE': '0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215', 13:16:29 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:16:29 INFO - '_': '/tools/buildbot/bin/python'} 13:16:30 INFO - Ignoring indexes: https://pypi.python.org/simple 13:16:30 INFO - Requirement already satisfied (use --upgrade to upgrade): jsonschema in ./venv/lib/python2.7/site-packages 13:16:30 INFO - Requirement already satisfied (use --upgrade to upgrade): functools32; python_version == "2.7" in ./venv/lib/python2.7/site-packages (from jsonschema) 13:16:30 INFO - Return code: 0 13:16:30 INFO - Running post-action listener: _resource_record_post_action 13:16:30 INFO - Running post-action listener: _start_resource_monitoring 13:16:30 INFO - Starting resource monitoring. 13:16:30 INFO - [mozharness: 2017-11-09 21:16:30.142580Z] Finished create-virtualenv step (success) 13:16:30 INFO - [mozharness: 2017-11-09 21:16:30.143163Z] Running install step. 13:16:30 INFO - Running pre-action listener: _resource_record_pre_action 13:16:30 INFO - Running main action method: install 13:16:30 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 13:16:30 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 13:16:30 INFO - Reading from file tmpfile_stdout 13:16:30 INFO - Reading from file tmpfile_stderr 13:16:30 INFO - Detecting whether we're running mozinstall >=1.0... 13:16:30 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h'] 13:16:30 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h 13:16:30 INFO - Reading from file tmpfile_stdout 13:16:30 INFO - Output received: 13:16:30 INFO - Usage: mozinstall [options] installer 13:16:30 INFO - Options: 13:16:30 INFO - -h, --help show this help message and exit 13:16:30 INFO - -d DEST, --destination=DEST 13:16:30 INFO - Directory to install application into. [default: 13:16:30 INFO - "/builds/slave/test"] 13:16:30 INFO - --app=APP Application being installed. [default: firefox] 13:16:30 INFO - mkdir: /builds/slave/test/build/application 13:16:30 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'] 13:16:30 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall /builds/slave/test/build/target.tar.bz2 --destination /builds/slave/test/build/application 13:16:48 INFO - Reading from file tmpfile_stdout 13:16:49 INFO - Output received: 13:16:49 INFO - /builds/slave/test/build/application/firefox/firefox 13:16:49 INFO - Running post-action listener: _resource_record_post_action 13:16:49 INFO - [mozharness: 2017-11-09 21:16:49.125611Z] Finished install step (success) 13:16:49 INFO - [mozharness: 2017-11-09 21:16:49.125861Z] Running setup-mitmproxy step. 13:16:49 INFO - Running pre-action listener: _resource_record_pre_action 13:16:49 INFO - Running main action method: setup_mitmproxy 13:16:49 INFO - Skipping: mitmproxy is not required 13:16:49 INFO - Running post-action listener: _resource_record_post_action 13:16:49 INFO - [mozharness: 2017-11-09 21:16:49.126803Z] Finished setup-mitmproxy step (success) 13:16:49 INFO - [mozharness: 2017-11-09 21:16:49.126894Z] Running run-tests step. 13:16:49 INFO - Running pre-action listener: _resource_record_pre_action 13:16:49 INFO - Running pre-action listener: _set_gcov_prefix 13:16:49 INFO - Running main action method: run_tests 13:16:49 WARNING - Try message not found. 13:16:49 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version'] 13:16:49 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version 13:16:49 INFO - Python 2.7.3 13:16:49 INFO - Return code: 0 13:16:49 INFO - grabbing minidump binary from tooltool 13:16:49 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')]} 13:16:49 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 0x1b6f070>, '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 0x1b70080>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1b6a2a0>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1 13:16:49 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 13:16:49 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 13:16:49 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 13:16:49 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache 13:16:49 INFO - Return code: 0 13:16:49 INFO - Chmoding /builds/slave/test/build/linux64-minidump_stackwalk to 0755 13:16:49 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir 13:16:49 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir 13:16:49 INFO - ENV: RUST_BACKTRACE is now full 13:16:49 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/linux64-minidump_stackwalk 13:16:49 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir 13:16:49 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/CuZ7j_4HT9Cb5o1Dot5Z3w/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-058', '--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 13:16:49 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/CuZ7j_4HT9Cb5o1Dot5Z3w/artifacts/public/build/target.crashreporter-symbols.zip --title talos-linux64-ix-058 --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 13:16:49 INFO - Using env: {'DISPLAY': ':0', 13:16:49 INFO - 'HOME': '/home/cltbld', 13:16:49 INFO - 'LANG': 'en_US.UTF-8', 13:16:49 INFO - 'LANGUAGE': 'en_US:en', 13:16:49 INFO - 'LOGNAME': 'cltbld', 13:16:49 INFO - 'MAIL': '/var/mail/cltbld', 13:16:49 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 13:16:49 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 13:16:49 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:16:49 INFO - 'MOZ_NO_REMOTE': '1', 13:16:49 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 13:16:49 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:16:49 INFO - 'NO_EM_RESTART': '1', 13:16:49 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:16:49 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:16:49 INFO - 'PWD': '/builds/slave/test', 13:16:49 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 13:16:49 INFO - 'RUST_BACKTRACE': 'full', 13:16:49 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 13:16:49 INFO - 'SHELL': '/bin/bash', 13:16:49 INFO - 'SHLVL': '1', 13:16:49 INFO - 'TERM': 'linux', 13:16:49 INFO - 'TMOUT': '86400', 13:16:49 INFO - 'USER': 'cltbld', 13:16:49 INFO - 'XDG_SESSION_COOKIE': '0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215', 13:16:49 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:16:49 INFO - '_': '/tools/buildbot/bin/python'} 13:16:49 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/CuZ7j_4HT9Cb5o1Dot5Z3w/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-058', '--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 13:16:49 INFO - mozversion application_buildid: 20171109194821 13:16:49 INFO - mozversion application_changeset: 6409f04e33d62148f988f567d1ef90a6f7b0ac9d 13:16:49 INFO - mozversion application_display_name: Nightly 13:16:49 INFO - mozversion application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384} 13:16:49 INFO - mozversion application_name: Firefox 13:16:49 INFO - mozversion application_remotingname: firefox 13:16:49 INFO - mozversion application_repository: https://hg.mozilla.org/mozilla-central 13:16:49 INFO - mozversion application_vendor: Mozilla 13:16:49 INFO - mozversion application_version: 58.0a1 13:16:49 INFO - mozversion platform_buildid: 20171109194821 13:16:49 INFO - mozversion platform_changeset: 6409f04e33d62148f988f567d1ef90a6f7b0ac9d 13:16:49 INFO - mozversion platform_repository: https://hg.mozilla.org/mozilla-central 13:16:49 INFO - mozversion platform_version: 58.0a1 13:16:49 INFO - using testdate: 1510262209 13:16:49 INFO - actual date: 1510262209 13:16:49 INFO - starting webserver on 'localhost:47376' 13:16:49 INFO - SUITE-START | Running 3 tests 13:16:49 INFO - TEST-START | basic_compositor_video 13:16:49 INFO - Initialising browser for basic_compositor_video test... 13:16:49 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:47376/getInfo.html -profile /tmp/tmp3hVBxh/profile 13:16:49 INFO - TEST-INFO | started process 3727 (/builds/slave/test/build/application/firefox/firefox http://localhost:47376/getInfo.html) 13:16:58 INFO - TEST-INFO | 3727: exit 0 13:16:58 INFO - Browser initialized. 13:16:58 INFO - Running cycle 1/1 for basic_compositor_video test... 13:16:58 INFO - Using env: {'DISPLAY': ':0', 13:16:58 INFO - 'HOME': '/home/cltbld', 13:16:58 INFO - 'JSGC_DISABLE_POISONING': '1', 13:16:58 INFO - 'LANG': 'en_US.UTF-8', 13:16:58 INFO - 'LANGUAGE': 'en_US:en', 13:16:58 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 13:16:58 INFO - 'LOGNAME': 'cltbld', 13:16:58 INFO - 'MAIL': '/var/mail/cltbld', 13:16:58 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 13:16:58 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 13:16:58 INFO - 'MOZ_CRASHREPORTER': '1', 13:16:58 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:16:58 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 13:16:58 INFO - 'MOZ_NO_REMOTE': '1', 13:16:58 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 13:16:58 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:16:58 INFO - 'NO_EM_RESTART': '1', 13:16:58 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:16:58 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:16:58 INFO - 'PWD': '/builds/slave/test', 13:16:58 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 13:16:58 INFO - 'RUST_BACKTRACE': 'full', 13:16:58 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 13:16:58 INFO - 'SHELL': '/bin/bash', 13:16:58 INFO - 'SHLVL': '1', 13:16:58 INFO - 'TERM': 'linux', 13:16:58 INFO - 'TMOUT': '86400', 13:16:58 INFO - 'USER': 'cltbld', 13:16:58 INFO - 'XDG_SESSION_COOKIE': '0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215', 13:16:58 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:16:58 INFO - '_': '/tools/buildbot/bin/python'} 13:16:58 INFO - TEST-INFO | started process 4003 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp3hVBxh/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/video/video.manifest.develop -tpnoisy -tpcycles 1 -tppagecycles 12) 13:16:59 INFO - PID 4003 | 13:16:59 INFO - PID 4003 | (/builds/slave/test/build/application/firefox/firefox:4055): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 13:16:59 INFO - PID 4003 | 13:17:45 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6801567749160136 ms/frame 13:17:45 INFO - PID 4003 | 13:17:45 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6668999999999998 ms/frame 13:17:45 INFO - PID 4003 | 13:17:45 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7051022727272724 ms/frame 13:17:45 INFO - PID 4003 | 13:17:45 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7021872340425546 ms/frame 13:17:45 INFO - PID 4003 | 13:17:45 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_2_startup = 4.172906815020862 ms/frame 13:17:45 INFO - PID 4003 | 13:17:45 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.057474645030424 ms/frame 13:17:45 INFO - PID 4003 | 13:17:45 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1_startup = 3.489627906976746 ms/frame 13:17:45 INFO - PID 4003 | 13:17:45 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1_inclip = 3.390669491525422 ms/frame 13:17:45 INFO - PID 4003 | 13:17:45 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.672202268431004 ms/frame 13:17:45 INFO - PID 4003 | 13:17:45 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.589022346368712 ms/frame 13:17:45 INFO - PID 4003 | 13:17:45 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_2_startup = 9.970299003322264 ms/frame 13:17:45 INFO - PID 4003 | 13:17:45 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_2_inclip = 9.709684466019416 ms/frame 13:17:45 INFO - PID 4003 | 13:17:45 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.950912408759134 ms/frame 13:17:45 INFO - PID 4003 | 13:17:45 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.47510471204186 ms/frame 13:17:45 INFO - PID 4003 | 13:17:45 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.299221311475389 ms/frame 13:17:45 INFO - PID 4003 | 13:17:45 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.69798245614037 ms/frame 13:17:45 INFO - PID 4003 | 13:17:45 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.196623134328357 ms/frame 13:17:45 INFO - PID 4003 | 13:17:45 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.63976063829788 ms/frame 13:17:45 INFO - PID 4003 | 13:17:45 INFO - PID 4003 | Cycle 1(1): loaded http://localhost:47376/tests/video/video_playback.html (next: http://localhost:47376/tests/video/video_playback.html) 13:18:31 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6905126760563383 ms/frame 13:18:31 INFO - PID 4003 | 13:18:31 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6711152882205516 ms/frame 13:18:31 INFO - PID 4003 | 13:18:31 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.783962544589774 ms/frame 13:18:31 INFO - PID 4003 | 13:18:31 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7338864818024262 ms/frame 13:18:31 INFO - PID 4003 | 13:18:31 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_2_startup = 4.172809457579972 ms/frame 13:18:31 INFO - PID 4003 | 13:18:31 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.811466666666664 ms/frame 13:18:31 INFO - PID 4003 | 13:18:31 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1_startup = 3.49323632130384 ms/frame 13:18:31 INFO - PID 4003 | 13:18:31 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1_inclip = 3.407385008517891 ms/frame 13:18:31 INFO - PID 4003 | 13:18:31 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.566725417439703 ms/frame 13:18:31 INFO - PID 4003 | 13:18:31 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.588268156424587 ms/frame 13:18:31 INFO - PID 4003 | 13:18:31 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_2_startup = 9.901600660066011 ms/frame 13:18:31 INFO - PID 4003 | 13:18:31 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_2_inclip = 10.258205128205121 ms/frame 13:18:31 INFO - PID 4003 | 13:18:31 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.951788321167886 ms/frame 13:18:31 INFO - PID 4003 | 13:18:31 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.695855614973262 ms/frame 13:18:31 INFO - PID 4003 | 13:18:31 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.348395061728379 ms/frame 13:18:31 INFO - PID 4003 | 13:18:31 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.561560693641628 ms/frame 13:18:31 INFO - PID 4003 | 13:18:31 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.153178438661717 ms/frame 13:18:31 INFO - PID 4003 | 13:18:31 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.87383152173911 ms/frame 13:18:31 INFO - PID 4003 | 13:18:31 INFO - PID 4003 | Cycle 1(2): loaded http://localhost:47376/tests/video/video_playback.html (next: http://localhost:47376/tests/video/video_playback.html) 13:19:18 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6866975829117483 ms/frame 13:19:18 INFO - PID 4003 | 13:19:18 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6688698915763136 ms/frame 13:19:18 INFO - PID 4003 | 13:19:18 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7356362058993637 ms/frame 13:19:18 INFO - PID 4003 | 13:19:18 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.6940304826418293 ms/frame 13:19:18 INFO - PID 4003 | 13:19:18 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_2_startup = 4.0005066666666655 ms/frame 13:19:18 INFO - PID 4003 | 13:19:18 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.124082474226805 ms/frame 13:19:18 INFO - PID 4003 | 13:19:18 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1_startup = 3.4727546296296286 ms/frame 13:19:18 INFO - PID 4003 | 13:19:18 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4071550255536627 ms/frame 13:19:18 INFO - PID 4003 | 13:19:18 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.608308411214953 ms/frame 13:19:18 INFO - PID 4003 | 13:19:18 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.682400568181823 ms/frame 13:19:18 INFO - PID 4003 | 13:19:18 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_2_startup = 9.902607260726066 ms/frame 13:19:18 INFO - PID 4003 | 13:19:18 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_2_inclip = 9.71196601941748 ms/frame 13:19:18 INFO - PID 4003 | 13:19:18 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.954215328467146 ms/frame 13:19:18 INFO - PID 4003 | 13:19:18 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.643324468085105 ms/frame 13:19:18 INFO - PID 4003 | 13:19:18 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.003020000000019 ms/frame 13:19:18 INFO - PID 4003 | 13:19:18 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.495545977011487 ms/frame 13:19:18 INFO - PID 4003 | 13:19:18 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.237696629213497 ms/frame 13:19:18 INFO - PID 4003 | 13:19:18 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.757876344086002 ms/frame 13:19:18 INFO - PID 4003 | 13:19:18 INFO - PID 4003 | Cycle 1(3): loaded http://localhost:47376/tests/video/video_playback.html (next: http://localhost:47376/tests/video/video_playback.html) 13:20:04 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6770933482392398 ms/frame 13:20:04 INFO - PID 4003 | 13:20:04 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6702796327212024 ms/frame 13:20:04 INFO - PID 4003 | 13:20:04 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.6987825594563988 ms/frame 13:20:04 INFO - PID 4003 | 13:20:04 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.6914539306846996 ms/frame 13:20:04 INFO - PID 4003 | 13:20:04 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_2_startup = 3.989468085106383 ms/frame 13:20:04 INFO - PID 4003 | 13:20:04 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.0339314516129035 ms/frame 13:20:04 INFO - PID 4003 | 13:20:04 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1_startup = 3.5258754406580497 ms/frame 13:20:04 INFO - PID 4003 | 13:20:04 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3787077702702697 ms/frame 13:20:04 INFO - PID 4003 | 13:20:04 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.367808586762075 ms/frame 13:20:04 INFO - PID 4003 | 13:20:04 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.5870810055866 ms/frame 13:20:04 INFO - PID 4003 | 13:20:04 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_2_startup = 10.454250871080148 ms/frame 13:20:04 INFO - PID 4003 | 13:20:04 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_2_inclip = 9.26155092592592 ms/frame 13:20:04 INFO - PID 4003 | 13:20:04 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.949580291970808 ms/frame 13:20:04 INFO - PID 4003 | 13:20:04 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.26010256410257 ms/frame 13:20:04 INFO - PID 4003 | 13:20:04 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.452676348547723 ms/frame 13:20:04 INFO - PID 4003 | 13:20:04 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.76829411764702 ms/frame 13:20:04 INFO - PID 4003 | 13:20:04 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.321584905660382 ms/frame 13:20:04 INFO - PID 4003 | 13:20:04 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.934371584699482 ms/frame 13:20:04 INFO - PID 4003 | 13:20:04 INFO - PID 4003 | Cycle 1(4): loaded http://localhost:47376/tests/video/video_playback.html (next: http://localhost:47376/tests/video/video_playback.html) 13:20:50 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6874268841394826 ms/frame 13:20:50 INFO - PID 4003 | 13:20:50 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.670025041736227 ms/frame 13:20:50 INFO - PID 4003 | 13:20:50 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.757858816637376 ms/frame 13:20:50 INFO - PID 4003 | 13:20:50 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7097948717948719 ms/frame 13:20:50 INFO - PID 4003 | 13:20:50 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_2_startup = 4.06630758807588 ms/frame 13:20:50 INFO - PID 4003 | 13:20:50 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.930599214145382 ms/frame 13:20:50 INFO - PID 4003 | 13:20:50 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1_startup = 3.6060336538461533 ms/frame 13:20:50 INFO - PID 4003 | 13:20:50 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4965646853146852 ms/frame 13:20:50 INFO - PID 4003 | 13:20:50 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.619147940074907 ms/frame 13:20:50 INFO - PID 4003 | 13:20:50 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.512424242424238 ms/frame 13:20:50 INFO - PID 4003 | 13:20:50 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_2_startup = 9.9353476821192 ms/frame 13:20:50 INFO - PID 4003 | 13:20:50 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_2_inclip = 9.570478468899537 ms/frame 13:20:50 INFO - PID 4003 | 13:20:50 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.948941605839423 ms/frame 13:20:50 INFO - PID 4003 | 13:20:50 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.257641025641016 ms/frame 13:20:50 INFO - PID 4003 | 13:20:50 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.715932203389826 ms/frame 13:20:50 INFO - PID 4003 | 13:20:50 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.767558823529415 ms/frame 13:20:50 INFO - PID 4003 | 13:20:50 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.498352490421484 ms/frame 13:20:50 INFO - PID 4003 | 13:20:50 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.872228260869553 ms/frame 13:20:50 INFO - PID 4003 | 13:20:50 INFO - PID 4003 | Cycle 1(5): loaded http://localhost:47376/tests/video/video_playback.html (next: http://localhost:47376/tests/video/video_playback.html) 13:21:36 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1_startup = 1.683611111111111 ms/frame 13:21:36 INFO - PID 4003 | 13:21:36 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6743807531380759 ms/frame 13:21:36 INFO - PID 4003 | 13:21:36 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7385312862108921 ms/frame 13:21:36 INFO - PID 4003 | 13:21:36 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7067107508532426 ms/frame 13:21:36 INFO - PID 4003 | 13:21:36 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_2_startup = 4.109904109589043 ms/frame 13:21:36 INFO - PID 4003 | 13:21:36 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.993602794411178 ms/frame 13:21:36 INFO - PID 4003 | 13:21:36 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1_startup = 3.522388497652583 ms/frame 13:21:36 INFO - PID 4003 | 13:21:36 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4021938775510168 ms/frame 13:21:36 INFO - PID 4003 | 13:21:36 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.704220532319395 ms/frame 13:21:36 INFO - PID 4003 | 13:21:36 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.684559659090909 ms/frame 13:21:36 INFO - PID 4003 | 13:21:36 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_2_startup = 9.934751655629146 ms/frame 13:21:36 INFO - PID 4003 | 13:21:36 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_2_inclip = 10.003649999999999 ms/frame 13:21:36 INFO - PID 4003 | 13:21:36 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.870561594202904 ms/frame 13:21:36 INFO - PID 4003 | 13:21:36 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.873097826086964 ms/frame 13:21:36 INFO - PID 4003 | 13:21:36 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.502937499999977 ms/frame 13:21:36 INFO - PID 4003 | 13:21:36 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.697280701754389 ms/frame 13:21:36 INFO - PID 4003 | 13:21:36 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.280582706766925 ms/frame 13:21:36 INFO - PID 4003 | 13:21:36 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.695374331550822 ms/frame 13:21:36 INFO - PID 4003 | 13:21:36 INFO - PID 4003 | Cycle 1(6): loaded http://localhost:47376/tests/video/video_playback.html (next: http://localhost:47376/tests/video/video_playback.html) 13:22:22 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6811708683473388 ms/frame 13:22:22 INFO - PID 4003 | 13:22:22 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6716332497911446 ms/frame 13:22:22 INFO - PID 4003 | 13:22:22 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7307151095732407 ms/frame 13:22:22 INFO - PID 4003 | 13:22:22 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.6994435004248094 ms/frame 13:22:22 INFO - PID 4003 | 13:22:22 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_2_startup = 4.138351724137931 ms/frame 13:22:22 INFO - PID 4003 | 13:22:22 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.159667359667358 ms/frame 13:22:22 INFO - PID 4003 | 13:22:22 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1_startup = 3.6233091787439595 ms/frame 13:22:22 INFO - PID 4003 | 13:22:22 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4910122164048905 ms/frame 13:22:22 INFO - PID 4003 | 13:22:22 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.6819507575757635 ms/frame 13:22:22 INFO - PID 4003 | 13:22:22 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.6362253521126675 ms/frame 13:22:22 INFO - PID 4003 | 13:22:22 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_2_startup = 10.274726027397264 ms/frame 13:22:22 INFO - PID 4003 | 13:22:22 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_2_inclip = 10.051834170854265 ms/frame 13:22:22 INFO - PID 4003 | 13:22:22 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.07520295202951 ms/frame 13:22:22 INFO - PID 4003 | 13:22:22 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.585291005291019 ms/frame 13:22:22 INFO - PID 4003 | 13:22:22 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.100604838709666 ms/frame 13:22:22 INFO - PID 4003 | 13:22:22 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.497701149425279 ms/frame 13:22:22 INFO - PID 4003 | 13:22:22 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.152825278810411 ms/frame 13:22:22 INFO - PID 4003 | 13:22:22 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.752607526881723 ms/frame 13:22:22 INFO - PID 4003 | 13:22:22 INFO - PID 4003 | Cycle 1(7): loaded http://localhost:47376/tests/video/video_playback.html (next: http://localhost:47376/tests/video/video_playback.html) 13:23:09 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6828154795288839 ms/frame 13:23:09 INFO - PID 4003 | 13:23:09 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.667629166666667 ms/frame 13:23:09 INFO - PID 4003 | 13:23:09 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7526898364485979 ms/frame 13:23:09 INFO - PID 4003 | 13:23:09 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7611047535211266 ms/frame 13:23:09 INFO - PID 4003 | 13:23:09 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_2_startup = 4.160950069348128 ms/frame 13:23:09 INFO - PID 4003 | 13:23:09 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.098719262295081 ms/frame 13:23:09 INFO - PID 4003 | 13:23:09 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1_startup = 3.559472123368921 ms/frame 13:23:09 INFO - PID 4003 | 13:23:09 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1_inclip = 3.5157029876977175 ms/frame 13:23:09 INFO - PID 4003 | 13:23:09 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.651374764595105 ms/frame 13:23:09 INFO - PID 4003 | 13:23:09 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.527651933701653 ms/frame 13:23:09 INFO - PID 4003 | 13:23:09 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_2_startup = 10.101043771043777 ms/frame 13:23:09 INFO - PID 4003 | 13:23:09 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_2_inclip = 9.853596059113295 ms/frame 13:23:09 INFO - PID 4003 | 13:23:09 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.87244565217392 ms/frame 13:23:09 INFO - PID 4003 | 13:23:09 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.365103626942988 ms/frame 13:23:09 INFO - PID 4003 | 13:23:09 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.401260330578525 ms/frame 13:23:09 INFO - PID 4003 | 13:23:09 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.768911764705905 ms/frame 13:23:09 INFO - PID 4003 | 13:23:09 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.452061068702271 ms/frame 13:23:09 INFO - PID 4003 | 13:23:09 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.115166666666685 ms/frame 13:23:09 INFO - PID 4003 | 13:23:09 INFO - PID 4003 | Cycle 1(8): loaded http://localhost:47376/tests/video/video_playback.html (next: http://localhost:47376/tests/video/video_playback.html) 13:23:55 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1_startup = 1.678992725237829 ms/frame 13:23:55 INFO - PID 4003 | 13:23:55 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6730016722408025 ms/frame 13:23:55 INFO - PID 4003 | 13:23:55 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7205991972477066 ms/frame 13:23:55 INFO - PID 4003 | 13:23:55 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.703952299829642 ms/frame 13:23:55 INFO - PID 4003 | 13:23:55 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_2_startup = 4.220133614627285 ms/frame 13:23:55 INFO - PID 4003 | 13:23:55 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.9536758893280624 ms/frame 13:23:55 INFO - PID 4003 | 13:23:55 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1_startup = 3.632602905569008 ms/frame 13:23:55 INFO - PID 4003 | 13:23:55 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1_inclip = 3.485252613240418 ms/frame 13:23:55 INFO - PID 4003 | 13:23:55 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.577797397769516 ms/frame 13:23:55 INFO - PID 4003 | 13:23:55 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.49692307692308 ms/frame 13:23:55 INFO - PID 4003 | 13:23:55 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_2_startup = 10.275428082191779 ms/frame 13:23:55 INFO - PID 4003 | 13:23:55 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_2_inclip = 9.711747572815547 ms/frame 13:23:55 INFO - PID 4003 | 13:23:55 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.031562499999996 ms/frame 13:23:55 INFO - PID 4003 | 13:23:55 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.754543010752695 ms/frame 13:23:55 INFO - PID 4003 | 13:23:55 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.248122448979595 ms/frame 13:23:55 INFO - PID 4003 | 13:23:55 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.905446428571416 ms/frame 13:23:55 INFO - PID 4003 | 13:23:55 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.583803088803096 ms/frame 13:23:55 INFO - PID 4003 | 13:23:55 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.929453551912589 ms/frame 13:23:55 INFO - PID 4003 | 13:23:55 INFO - PID 4003 | Cycle 1(9): loaded http://localhost:47376/tests/video/video_playback.html (next: http://localhost:47376/tests/video/video_playback.html) 13:24:41 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6830959057767807 ms/frame 13:24:41 INFO - PID 4003 | 13:24:41 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.668390325271059 ms/frame 13:24:41 INFO - PID 4003 | 13:24:41 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7425783972125437 ms/frame 13:24:41 INFO - PID 4003 | 13:24:41 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7111035072711718 ms/frame 13:24:41 INFO - PID 4003 | 13:24:41 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_2_startup = 4.191061452513968 ms/frame 13:24:41 INFO - PID 4003 | 13:24:41 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.041313131313129 ms/frame 13:24:41 INFO - PID 4003 | 13:24:41 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1_startup = 3.4605420991926192 ms/frame 13:24:41 INFO - PID 4003 | 13:24:41 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3744266441821247 ms/frame 13:24:41 INFO - PID 4003 | 13:24:41 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.67148393194707 ms/frame 13:24:41 INFO - PID 4003 | 13:24:41 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.363914209115276 ms/frame 13:24:41 INFO - PID 4003 | 13:24:41 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_2_startup = 10.454843205574916 ms/frame 13:24:41 INFO - PID 4003 | 13:24:41 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_2_inclip = 9.954950248756218 ms/frame 13:24:41 INFO - PID 4003 | 13:24:41 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.114074074074072 ms/frame 13:24:41 INFO - PID 4003 | 13:24:41 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.53086842105262 ms/frame 13:24:41 INFO - PID 4003 | 13:24:41 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.60949579831935 ms/frame 13:24:41 INFO - PID 4003 | 13:24:41 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.123727272727278 ms/frame 13:24:41 INFO - PID 4003 | 13:24:41 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.496149425287367 ms/frame 13:24:41 INFO - PID 4003 | 13:24:41 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.934426229508198 ms/frame 13:24:41 INFO - PID 4003 | 13:24:41 INFO - PID 4003 | Cycle 1(10): loaded http://localhost:47376/tests/video/video_playback.html (next: http://localhost:47376/tests/video/video_playback.html) 13:25:27 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6798936170212766 ms/frame 13:25:27 INFO - PID 4003 | 13:25:27 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6711236424394322 ms/frame 13:25:27 INFO - PID 4003 | 13:25:27 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7402146171693735 ms/frame 13:25:27 INFO - PID 4003 | 13:25:27 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.704182282793868 ms/frame 13:25:27 INFO - PID 4003 | 13:25:27 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_2_startup = 4.202612044817928 ms/frame 13:25:27 INFO - PID 4003 | 13:25:27 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.9697519841269826 ms/frame 13:25:27 INFO - PID 4003 | 13:25:27 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1_startup = 3.559347568208779 ms/frame 13:25:27 INFO - PID 4003 | 13:25:27 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4731944444444403 ms/frame 13:25:27 INFO - PID 4003 | 13:25:27 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.629015009380862 ms/frame 13:25:27 INFO - PID 4003 | 13:25:27 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.635422535211269 ms/frame 13:25:27 INFO - PID 4003 | 13:25:27 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_2_startup = 9.968006644518269 ms/frame 13:25:27 INFO - PID 4003 | 13:25:27 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_2_inclip = 9.85541871921183 ms/frame 13:25:27 INFO - PID 4003 | 13:25:27 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.1152962962963 ms/frame 13:25:27 INFO - PID 4003 | 13:25:27 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.700347593582869 ms/frame 13:25:27 INFO - PID 4003 | 13:25:27 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.397438016528927 ms/frame 13:25:27 INFO - PID 4003 | 13:25:27 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.695672514619877 ms/frame 13:25:27 INFO - PID 4003 | 13:25:27 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.408935361216713 ms/frame 13:25:27 INFO - PID 4003 | 13:25:27 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.63930851063831 ms/frame 13:25:27 INFO - PID 4003 | 13:25:27 INFO - PID 4003 | Cycle 1(11): loaded http://localhost:47376/tests/video/video_playback.html (next: http://localhost:47376/tests/video/video_playback.html) 13:26:13 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1_startup = 1.679890817469205 ms/frame 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6698080133555926 ms/frame 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7385457705677865 ms/frame 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7228596037898363 ms/frame 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_2_startup = 4.184895397489539 ms/frame 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.8623359073359085 ms/frame 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1_startup = 3.4649364896073904 ms/frame 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1_inclip = 3.38484771573604 ms/frame 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.704591254752855 ms/frame 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.587695530726259 ms/frame 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_2_startup = 10.276917808219167 ms/frame 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | testsrc.480p.60fps.webm_scale_2_inclip = 9.951691542288561 ms/frame 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.910254545454544 ms/frame 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.364170984455976 ms/frame 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.248755102040816 ms/frame 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.90830357142858 ms/frame 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.364450757575744 ms/frame 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.929890710382503 ms/frame 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | Cycle 1(12): loaded http://localhost:47376/tests/video/video_playback.html (next: http://localhost:47376/tests/video/video_playback.html) 13:26:13 INFO - PID 4003 | __start_tp_report 13:26:13 INFO - PID 4003 | _x_x_mozilla_page_load 13:26:13 INFO - PID 4003 | _x_x_mozilla_page_load_details 13:26:13 INFO - PID 4003 | |i|pagename|runs| 13:26:13 INFO - PID 4003 | |0;240p.120fps.mp4_scale_1_startup;1.6801567749160136;1.6905126760563383;1.6866975829117483;1.6770933482392398;1.6874268841394826;1.683611111111111;1.6811708683473388;1.6828154795288839;1.678992725237829;1.6830959057767807;1.6798936170212766;1.679890817469205 13:26:13 INFO - PID 4003 | |1;240p.120fps.mp4_scale_1_inclip;1.6668999999999998;1.6711152882205516;1.6688698915763136;1.6702796327212024;1.670025041736227;1.6743807531380759;1.6716332497911446;1.667629166666667;1.6730016722408025;1.668390325271059;1.6711236424394322;1.6698080133555926 13:26:13 INFO - PID 4003 | |2;240p.120fps.mp4_scale_1.1_startup;1.7051022727272724;1.783962544589774;1.7356362058993637;1.6987825594563988;1.757858816637376;1.7385312862108921;1.7307151095732407;1.7526898364485979;1.7205991972477066;1.7425783972125437;1.7402146171693735;1.7385457705677865 13:26:13 INFO - PID 4003 | |3;240p.120fps.mp4_scale_1.1_inclip;1.7021872340425546;1.7338864818024262;1.6940304826418293;1.6914539306846996;1.7097948717948719;1.7067107508532426;1.6994435004248094;1.7611047535211266;1.703952299829642;1.7111035072711718;1.704182282793868;1.7228596037898363 13:26:13 INFO - PID 4003 | |4;240p.120fps.mp4_scale_2_startup;4.172906815020862;4.172809457579972;4.0005066666666655;3.989468085106383;4.06630758807588;4.109904109589043;4.138351724137931;4.160950069348128;4.220133614627285;4.191061452513968;4.202612044817928;4.184895397489539 13:26:13 INFO - PID 4003 | |5;240p.120fps.mp4_scale_2_inclip;4.057474645030424;3.811466666666664;4.124082474226805;4.0339314516129035;3.930599214145382;3.993602794411178;4.159667359667358;4.098719262295081;3.9536758893280624;4.041313131313129;3.9697519841269826;3.8623359073359085 13:26:13 INFO - PID 4003 | |6;480p.60fps.webm_scale_1_startup;3.489627906976746;3.49323632130384;3.4727546296296286;3.5258754406580497;3.6060336538461533;3.522388497652583;3.6233091787439595;3.559472123368921;3.632602905569008;3.4605420991926192;3.559347568208779;3.4649364896073904 13:26:13 INFO - PID 4003 | |7;480p.60fps.webm_scale_1_inclip;3.390669491525422;3.407385008517891;3.4071550255536627;3.3787077702702697;3.4965646853146852;3.4021938775510168;3.4910122164048905;3.5157029876977175;3.485252613240418;3.3744266441821247;3.4731944444444403;3.38484771573604 13:26:13 INFO - PID 4003 | |8;480p.60fps.webm_scale_1.1_startup;5.672202268431004;5.566725417439703;5.608308411214953;5.367808586762075;5.619147940074907;5.704220532319395;5.6819507575757635;5.651374764595105;5.577797397769516;5.67148393194707;5.629015009380862;5.704591254752855 13:26:13 INFO - PID 4003 | |9;480p.60fps.webm_scale_1.1_inclip;5.589022346368712;5.588268156424587;5.682400568181823;5.5870810055866;5.512424242424238;5.684559659090909;5.6362253521126675;5.527651933701653;5.49692307692308;5.363914209115276;5.635422535211269;5.587695530726259 13:26:13 INFO - PID 4003 | |10;480p.60fps.webm_scale_2_startup;9.970299003322264;9.901600660066011;9.902607260726066;10.454250871080148;9.9353476821192;9.934751655629146;10.274726027397264;10.101043771043777;10.275428082191779;10.454843205574916;9.968006644518269;10.276917808219167 13:26:13 INFO - PID 4003 | |11;480p.60fps.webm_scale_2_inclip;9.709684466019416;10.258205128205121;9.71196601941748;9.26155092592592;9.570478468899537;10.003649999999999;10.051834170854265;9.853596059113295;9.711747572815547;9.954950248756218;9.85541871921183;9.951691542288561 13:26:13 INFO - PID 4003 | |12;1080p.60fps.mp4_scale_1_startup;10.950912408759134;10.951788321167886;10.954215328467146;10.949580291970808;10.948941605839423;10.870561594202904;11.07520295202951;10.87244565217392;11.031562499999996;11.114074074074072;11.1152962962963;10.910254545454544 13:26:13 INFO - PID 4003 | |13;1080p.60fps.mp4_scale_1_inclip;10.47510471204186;10.695855614973262;10.643324468085105;10.26010256410257;10.257641025641016;10.873097826086964;10.585291005291019;10.365103626942988;10.754543010752695;10.53086842105262;10.700347593582869;10.364170984455976 13:26:13 INFO - PID 4003 | |14;1080p.60fps.mp4_scale_1.1_startup;12.299221311475389;12.348395061728379;12.003020000000019;12.452676348547723;12.715932203389826;12.502937499999977;12.100604838709666;12.401260330578525;12.248122448979595;12.60949579831935;12.397438016528927;12.248755102040816 13:26:13 INFO - PID 4003 | |15;1080p.60fps.mp4_scale_1.1_inclip;11.69798245614037;11.561560693641628;11.495545977011487;11.76829411764702;11.767558823529415;11.697280701754389;11.497701149425279;11.768911764705905;11.905446428571416;12.123727272727278;11.695672514619877;11.90830357142858 13:26:13 INFO - PID 4003 | |16;1080p.60fps.mp4_scale_2_startup;11.196623134328357;11.153178438661717;11.237696629213497;11.321584905660382;11.498352490421484;11.280582706766925;11.152825278810411;11.452061068702271;11.583803088803096;11.496149425287367;11.408935361216713;11.364450757575744 13:26:13 INFO - PID 4003 | |17;1080p.60fps.mp4_scale_2_inclip;10.63976063829788;10.87383152173911;10.757876344086002;10.934371584699482;10.872228260869553;10.695374331550822;10.752607526881723;11.115166666666685;10.929453551912589;10.934426229508198;10.63930851063831;10.929890710382503 13:26:13 INFO - PID 4003 | __end_tp_report 13:26:13 INFO - PID 4003 | __start_cc_report 13:26:13 INFO - PID 4003 | _x_x_mozilla_cycle_collect,560 13:26:13 INFO - PID 4003 | __end_cc_report 13:26:13 INFO - PID 4003 | __startTimestamp1510262773897__endTimestamp 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | ------- Summary: start ------- 13:26:13 INFO - PID 4003 | Number of tests: 18 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | [#0] 240p.120fps.mp4_scale_1_startup Cycles:12 Average:1.68 Median:1.68 stddev:0.00 (0.2%) stddev-sans-first:0.00 13:26:13 INFO - PID 4003 | Values: 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | [#1] 240p.120fps.mp4_scale_1_inclip Cycles:12 Average:1.67 Median:1.67 stddev:0.00 (0.1%) stddev-sans-first:0.00 13:26:13 INFO - PID 4003 | Values: 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | [#2] 240p.120fps.mp4_scale_1.1_startup Cycles:12 Average:1.74 Median:1.74 stddev:0.02 (1.3%) stddev-sans-first:0.02 13:26:13 INFO - PID 4003 | Values: 1.7 1.8 1.7 1.7 1.8 1.7 1.7 1.8 1.7 1.7 1.7 1.7 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | [#3] 240p.120fps.mp4_scale_1.1_inclip Cycles:12 Average:1.71 Median:1.71 stddev:0.02 (1.1%) stddev-sans-first:0.02 13:26:13 INFO - PID 4003 | Values: 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.8 1.7 1.7 1.7 1.7 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | [#4] 240p.120fps.mp4_scale_2_startup Cycles:12 Average:4.13 Median:4.17 stddev:0.08 (1.9%) stddev-sans-first:0.08 13:26:13 INFO - PID 4003 | Values: 4.2 4.2 4.0 4.0 4.1 4.1 4.1 4.2 4.2 4.2 4.2 4.2 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | [#5] 240p.120fps.mp4_scale_2_inclip Cycles:12 Average:4.00 Median:4.04 stddev:0.10 (2.6%) stddev-sans-first:0.11 13:26:13 INFO - PID 4003 | Values: 4.1 3.8 4.1 4.0 3.9 4.0 4.2 4.1 4.0 4.0 4.0 3.9 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | [#6] 480p.60fps.webm_scale_1_startup Cycles:12 Average:3.53 Median:3.54 stddev:0.06 (1.7%) stddev-sans-first:0.06 13:26:13 INFO - PID 4003 | Values: 3.5 3.5 3.5 3.5 3.6 3.5 3.6 3.6 3.6 3.5 3.6 3.5 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | [#7] 480p.60fps.webm_scale_1_inclip Cycles:12 Average:3.43 Median:3.44 stddev:0.05 (1.6%) stddev-sans-first:0.05 13:26:13 INFO - PID 4003 | Values: 3.4 3.4 3.4 3.4 3.5 3.4 3.5 3.5 3.5 3.4 3.5 3.4 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | [#8] 480p.60fps.webm_scale_1.1_startup Cycles:12 Average:5.62 Median:5.66 stddev:0.09 (1.6%) stddev-sans-first:0.09 13:26:13 INFO - PID 4003 | Values: 5.7 5.6 5.6 5.4 5.6 5.7 5.7 5.7 5.6 5.7 5.6 5.7 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | [#9] 480p.60fps.webm_scale_1.1_inclip Cycles:12 Average:5.57 Median:5.59 stddev:0.09 (1.6%) stddev-sans-first:0.09 13:26:13 INFO - PID 4003 | Values: 5.6 5.6 5.7 5.6 5.5 5.7 5.6 5.5 5.5 5.4 5.6 5.6 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | [#10] 480p.60fps.webm_scale_2_startup Cycles:12 Average:10.12 Median:9.90 stddev:0.21 (2.2%) stddev-sans-first:0.22 13:26:13 INFO - PID 4003 | Values: 10.0 9.9 9.9 10.5 9.9 9.9 10.3 10.1 10.3 10.5 10.0 10.3 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | [#11] 480p.60fps.webm_scale_2_inclip Cycles:12 Average:9.82 Median:9.71 stddev:0.26 (2.6%) stddev-sans-first:0.27 13:26:13 INFO - PID 4003 | Values: 9.7 10.3 9.7 9.3 9.6 10.0 10.1 9.9 9.7 10.0 9.9 10.0 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | [#12] 1080p.60fps.mp4_scale_1_startup Cycles:12 Average:10.98 Median:10.95 stddev:0.09 (0.8%) stddev-sans-first:0.09 13:26:13 INFO - PID 4003 | Values: 11.0 11.0 11.0 10.9 10.9 10.9 11.1 10.9 11.0 11.1 11.1 10.9 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | [#13] 1080p.60fps.mp4_scale_1_inclip Cycles:12 Average:10.54 Median:10.61 stddev:0.20 (1.9%) stddev-sans-first:0.21 13:26:13 INFO - PID 4003 | Values: 10.5 10.7 10.6 10.3 10.3 10.9 10.6 10.4 10.8 10.5 10.7 10.4 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | [#14] 1080p.60fps.mp4_scale_1.1_startup Cycles:12 Average:12.36 Median:12.40 stddev:0.20 (1.6%) stddev-sans-first:0.21 13:26:13 INFO - PID 4003 | Values: 12.3 12.3 12.0 12.5 12.7 12.5 12.1 12.4 12.2 12.6 12.4 12.2 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | [#15] 1080p.60fps.mp4_scale_1.1_inclip Cycles:12 Average:11.74 Median:11.77 stddev:0.18 (1.5%) stddev-sans-first:0.19 13:26:13 INFO - PID 4003 | Values: 11.7 11.6 11.5 11.8 11.8 11.7 11.5 11.8 11.9 12.1 11.7 11.9 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | [#16] 1080p.60fps.mp4_scale_2_startup Cycles:12 Average:11.35 Median:11.39 stddev:0.14 (1.3%) stddev-sans-first:0.14 13:26:13 INFO - PID 4003 | Values: 11.2 11.2 11.2 11.3 11.5 11.3 11.2 11.5 11.6 11.5 11.4 11.4 13:26:13 INFO - PID 4003 | 13:26:13 INFO - PID 4003 | [#17] 1080p.60fps.mp4_scale_2_inclip Cycles:12 Average:10.84 Median:10.90 stddev:0.14 (1.3%) stddev-sans-first:0.14 13:26:13 INFO - PID 4003 | Values: 10.6 10.9 10.8 10.9 10.9 10.7 10.8 11.1 10.9 10.9 10.6 10.9 13:26:13 INFO - PID 4003 | -------- Summary: end -------- 13:26:13 INFO - PID 4003 | 13:26:14 INFO - TEST-INFO | 4003: exit 0 13:26:14 INFO - TEST-OK | basic_compositor_video | took 564547ms 13:26:14 INFO - TEST-START | glvideo 13:26:14 INFO - Initialising browser for glvideo test... 13:26:14 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:47376/getInfo.html -profile /tmp/tmpQgbFtd/profile 13:26:14 INFO - TEST-INFO | started process 5262 (/builds/slave/test/build/application/firefox/firefox http://localhost:47376/getInfo.html) 13:26:19 INFO - TEST-INFO | 5262: exit 0 13:26:19 INFO - Browser initialized. 13:26:19 INFO - Running cycle 1/1 for glvideo test... 13:26:19 INFO - Using env: {'DISPLAY': ':0', 13:26:19 INFO - 'HOME': '/home/cltbld', 13:26:19 INFO - 'JSGC_DISABLE_POISONING': '1', 13:26:19 INFO - 'LANG': 'en_US.UTF-8', 13:26:19 INFO - 'LANGUAGE': 'en_US:en', 13:26:19 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 13:26:19 INFO - 'LOGNAME': 'cltbld', 13:26:19 INFO - 'MAIL': '/var/mail/cltbld', 13:26:19 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 13:26:19 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 13:26:19 INFO - 'MOZ_CRASHREPORTER': '1', 13:26:19 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:26:19 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 13:26:19 INFO - 'MOZ_NO_REMOTE': '1', 13:26:19 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 13:26:19 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:26:19 INFO - 'NO_EM_RESTART': '1', 13:26:19 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:26:19 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:26:19 INFO - 'PWD': '/builds/slave/test', 13:26:19 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 13:26:19 INFO - 'RUST_BACKTRACE': 'full', 13:26:19 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 13:26:19 INFO - 'SHELL': '/bin/bash', 13:26:19 INFO - 'SHLVL': '1', 13:26:19 INFO - 'TERM': 'linux', 13:26:19 INFO - 'TMOUT': '86400', 13:26:19 INFO - 'USER': 'cltbld', 13:26:19 INFO - 'XDG_SESSION_COOKIE': '0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215', 13:26:19 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:26:19 INFO - '_': '/tools/buildbot/bin/python'} 13:26:19 INFO - TEST-INFO | started process 5542 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpQgbFtd/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/webgl/glvideo.manifest.develop -tpnoisy -tploadnocache -tpcycles 1 -tppagecycles 5) 13:26:20 INFO - PID 5542 | 13:26:20 INFO - PID 5542 | (/builds/slave/test/build/application/firefox/firefox:5593): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 13:26:20 INFO - PID 5542 | 13:26:22 INFO - PID 5542 | [talos glvideo result] Mean tick time across 100 ticks: 7.727950000000001 ms 13:26:22 INFO - PID 5542 | Cycle 1(1): loaded http://localhost:47376/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:47376/tests/webgl/benchmarks/video/video_upload.html) 13:26:23 INFO - PID 5542 | [talos glvideo result] Mean tick time across 100 ticks: 6.5192499999999995 ms 13:26:23 INFO - PID 5542 | Cycle 1(2): loaded http://localhost:47376/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:47376/tests/webgl/benchmarks/video/video_upload.html) 13:26:24 INFO - PID 5542 | [talos glvideo result] Mean tick time across 100 ticks: 6.48725 ms 13:26:24 INFO - PID 5542 | Cycle 1(3): loaded http://localhost:47376/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:47376/tests/webgl/benchmarks/video/video_upload.html) 13:26:26 INFO - PID 5542 | [talos glvideo result] Mean tick time across 100 ticks: 6.6024 ms 13:26:26 INFO - PID 5542 | Cycle 1(4): loaded http://localhost:47376/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:47376/tests/webgl/benchmarks/video/video_upload.html) 13:26:27 INFO - PID 5542 | [talos glvideo result] Mean tick time across 100 ticks: 6.674000000000001 ms 13:26:27 INFO - PID 5542 | Cycle 1(5): loaded http://localhost:47376/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:47376/tests/webgl/benchmarks/video/video_upload.html) 13:26:27 INFO - PID 5542 | __start_tp_report 13:26:27 INFO - PID 5542 | _x_x_mozilla_page_load 13:26:27 INFO - PID 5542 | _x_x_mozilla_page_load_details 13:26:27 INFO - PID 5542 | |i|pagename|runs| 13:26:27 INFO - PID 5542 | |0;Mean tick time across 100 ticks: ;7.727950000000001;6.5192499999999995;6.48725;6.6024;6.674000000000001 13:26:27 INFO - PID 5542 | __end_tp_report 13:26:27 INFO - PID 5542 | __start_cc_report 13:26:27 INFO - PID 5542 | _x_x_mozilla_cycle_collect,273 13:26:27 INFO - PID 5542 | __end_cc_report 13:26:27 INFO - PID 5542 | __startTimestamp1510262787815__endTimestamp 13:26:27 INFO - PID 5542 | 13:26:27 INFO - PID 5542 | ------- Summary: start ------- 13:26:27 INFO - PID 5542 | Number of tests: 1 13:26:27 INFO - PID 5542 | 13:26:27 INFO - PID 5542 | [#0] Mean tick time across 100 ticks: Cycles:5 Average:6.80 Median:6.60 stddev:0.52 (7.9%) stddev-sans-first:0.08 13:26:27 INFO - PID 5542 | Values: 7.7 6.5 6.5 6.6 6.7 13:26:27 INFO - PID 5542 | -------- Summary: end -------- 13:26:27 INFO - PID 5542 | 13:26:28 INFO - PID 5542 | *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping 13:26:28 INFO - TEST-INFO | 5542: exit 0 13:26:28 INFO - TEST-OK | glvideo | took 13978ms 13:26:28 INFO - TEST-START | displaylist_mutate 13:26:28 INFO - Initialising browser for displaylist_mutate test... 13:26:28 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:47376/getInfo.html -profile /tmp/tmpSztQmx/profile 13:26:28 INFO - TEST-INFO | started process 5767 (/builds/slave/test/build/application/firefox/firefox http://localhost:47376/getInfo.html) 13:26:34 INFO - TEST-INFO | 5767: exit 0 13:26:34 INFO - Browser initialized. 13:26:34 INFO - Running cycle 1/1 for displaylist_mutate test... 13:26:34 INFO - Using env: {'DISPLAY': ':0', 13:26:34 INFO - 'HOME': '/home/cltbld', 13:26:34 INFO - 'JSGC_DISABLE_POISONING': '1', 13:26:34 INFO - 'LANG': 'en_US.UTF-8', 13:26:34 INFO - 'LANGUAGE': 'en_US:en', 13:26:34 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 13:26:34 INFO - 'LOGNAME': 'cltbld', 13:26:34 INFO - 'MAIL': '/var/mail/cltbld', 13:26:34 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 13:26:34 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 13:26:34 INFO - 'MOZ_CRASHREPORTER': '1', 13:26:34 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:26:34 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 13:26:34 INFO - 'MOZ_NO_REMOTE': '1', 13:26:34 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 13:26:34 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:26:34 INFO - 'NO_EM_RESTART': '1', 13:26:34 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:26:34 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:26:34 INFO - 'PWD': '/builds/slave/test', 13:26:34 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 13:26:34 INFO - 'RUST_BACKTRACE': 'full', 13:26:34 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 13:26:34 INFO - 'SHELL': '/bin/bash', 13:26:34 INFO - 'SHLVL': '1', 13:26:34 INFO - 'TERM': 'linux', 13:26:34 INFO - 'TMOUT': '86400', 13:26:34 INFO - 'USER': 'cltbld', 13:26:34 INFO - 'XDG_SESSION_COOKIE': '0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215', 13:26:34 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:26:34 INFO - '_': '/tools/buildbot/bin/python'} 13:26:34 INFO - TEST-INFO | started process 6045 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpSztQmx/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/layout/displaylist_mutate.manifest.develop -tpnoisy -tploadnocache -tpcycles 1 -tppagecycles 5) 13:26:34 INFO - PID 6045 | 13:26:34 INFO - PID 6045 | (/builds/slave/test/build/application/firefox/firefox:6097): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 13:26:34 INFO - PID 6045 | 13:26:53 INFO - PID 6045 | Cycle 1(1): loaded http://localhost:47376/tests/layout/benchmarks/displaylist_mutate.html (next: http://localhost:47376/tests/layout/benchmarks/displaylist_mutate.html) 13:27:13 INFO - PID 6045 | Cycle 1(2): loaded http://localhost:47376/tests/layout/benchmarks/displaylist_mutate.html (next: http://localhost:47376/tests/layout/benchmarks/displaylist_mutate.html) 13:27:33 INFO - PID 6045 | Cycle 1(3): loaded http://localhost:47376/tests/layout/benchmarks/displaylist_mutate.html (next: http://localhost:47376/tests/layout/benchmarks/displaylist_mutate.html) 13:27:52 INFO - PID 6045 | Cycle 1(4): loaded http://localhost:47376/tests/layout/benchmarks/displaylist_mutate.html (next: http://localhost:47376/tests/layout/benchmarks/displaylist_mutate.html) 13:27:53 INFO - PID 6045 | Waiting for idle-callback 13:28:13 INFO - PID 6045 | Cycle 1(5): loaded http://localhost:47376/tests/layout/benchmarks/displaylist_mutate.html (next: http://localhost:47376/tests/layout/benchmarks/displaylist_mutate.html) 13:28:14 INFO - PID 6045 | __start_tp_report 13:28:14 INFO - PID 6045 | _x_x_mozilla_page_load 13:28:14 INFO - PID 6045 | _x_x_mozilla_page_load_details 13:28:14 INFO - PID 6045 | |i|pagename|runs| 13:28:14 INFO - PID 6045 | |0;/displaylist_mutate.html;18290.655;18753.620000000003;19001.055;19036.5;18800.004999999997 13:28:14 INFO - PID 6045 | __end_tp_report 13:28:14 INFO - PID 6045 | __start_cc_report 13:28:14 INFO - PID 6045 | _x_x_mozilla_cycle_collect,197 13:28:14 INFO - PID 6045 | __end_cc_report 13:28:14 INFO - PID 6045 | __startTimestamp1510262894031__endTimestamp 13:28:14 INFO - PID 6045 | 13:28:14 INFO - PID 6045 | ------- Summary: start ------- 13:28:14 INFO - PID 6045 | Number of tests: 1 13:28:14 INFO - PID 6045 | 13:28:14 INFO - PID 6045 | [#0] /displaylist_mutate.html Cycles:5 Average:18776.37 Median:18800.00 stddev:297.97 (1.6%) stddev-sans-first:141.72 13:28:14 INFO - PID 6045 | Values: 18290.7 18753.6 19001.1 19036.5 18800.0 13:28:14 INFO - PID 6045 | -------- Summary: end -------- 13:28:14 INFO - PID 6045 | 13:28:14 INFO - TEST-INFO | 6045: exit 0 13:28:14 INFO - TEST-OK | displaylist_mutate | took 106139ms 13:28:14 INFO - SUITE-END | took 684s 13:28:14 INFO - Completed test suite (00:11:24) 13:28:14 INFO - PERFHERDER_DATA: {"framework": {"name": "talos"}, "suites": [{"extraOptions": ["e10s"], "name": "basic_compositor_video", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 5.555214834196063, "subtests": [{"name": "240p.120fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.6801567749160136, 1.6905126760563383, 1.6866975829117483, 1.6770933482392398, 1.6874268841394826, 1.683611111111111, 1.6811708683473388, 1.6828154795288839, 1.678992725237829, 1.6830959057767807, 1.6798936170212766, 1.679890817469205], "value": 1.6828154795288839, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.6668999999999998, 1.6711152882205516, 1.6688698915763136, 1.6702796327212024, 1.670025041736227, 1.6743807531380759, 1.6716332497911446, 1.667629166666667, 1.6730016722408025, 1.668390325271059, 1.6711236424394322, 1.6698080133555926], "value": 1.6702796327212024, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.7051022727272724, 1.783962544589774, 1.7356362058993637, 1.6987825594563988, 1.757858816637376, 1.7385312862108921, 1.7307151095732407, 1.7526898364485979, 1.7205991972477066, 1.7425783972125437, 1.7402146171693735, 1.7385457705677865], "value": 1.7385457705677865, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.7021872340425546, 1.7338864818024262, 1.6940304826418293, 1.6914539306846996, 1.7097948717948719, 1.7067107508532426, 1.6994435004248094, 1.7611047535211266, 1.703952299829642, 1.7111035072711718, 1.704182282793868, 1.7228596037898363], "value": 1.7067107508532426, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.172906815020862, 4.172809457579972, 4.0005066666666655, 3.989468085106383, 4.06630758807588, 4.109904109589043, 4.138351724137931, 4.160950069348128, 4.220133614627285, 4.191061452513968, 4.202612044817928, 4.184895397489539], "value": 4.160950069348128, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.057474645030424, 3.811466666666664, 4.124082474226805, 4.0339314516129035, 3.930599214145382, 3.993602794411178, 4.159667359667358, 4.098719262295081, 3.9536758893280624, 4.041313131313129, 3.9697519841269826, 3.8623359073359085], "value": 3.993602794411178, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.489627906976746, 3.49323632130384, 3.4727546296296286, 3.5258754406580497, 3.6060336538461533, 3.522388497652583, 3.6233091787439595, 3.559472123368921, 3.632602905569008, 3.4605420991926192, 3.559347568208779, 3.4649364896073904], "value": 3.5258754406580497, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.390669491525422, 3.407385008517891, 3.4071550255536627, 3.3787077702702697, 3.4965646853146852, 3.4021938775510168, 3.4910122164048905, 3.5157029876977175, 3.485252613240418, 3.3744266441821247, 3.4731944444444403, 3.38484771573604], "value": 3.407385008517891, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.672202268431004, 5.566725417439703, 5.608308411214953, 5.367808586762075, 5.619147940074907, 5.704220532319395, 5.6819507575757635, 5.651374764595105, 5.577797397769516, 5.67148393194707, 5.629015009380862, 5.704591254752855], "value": 5.629015009380862, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.589022346368712, 5.588268156424587, 5.682400568181823, 5.5870810055866, 5.512424242424238, 5.684559659090909, 5.6362253521126675, 5.527651933701653, 5.49692307692308, 5.363914209115276, 5.635422535211269, 5.587695530726259], "value": 5.587695530726259, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [9.970299003322264, 9.901600660066011, 9.902607260726066, 10.454250871080148, 9.9353476821192, 9.934751655629146, 10.274726027397264, 10.101043771043777, 10.275428082191779, 10.454843205574916, 9.968006644518269, 10.276917808219167], "value": 10.101043771043777, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [9.709684466019416, 10.258205128205121, 9.71196601941748, 9.26155092592592, 9.570478468899537, 10.003649999999999, 10.051834170854265, 9.853596059113295, 9.711747572815547, 9.954950248756218, 9.85541871921183, 9.951691542288561], "value": 9.85541871921183, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.950912408759134, 10.951788321167886, 10.954215328467146, 10.949580291970808, 10.948941605839423, 10.870561594202904, 11.07520295202951, 10.87244565217392, 11.031562499999996, 11.114074074074072, 11.1152962962963, 10.910254545454544], "value": 10.951788321167886, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.47510471204186, 10.695855614973262, 10.643324468085105, 10.26010256410257, 10.257641025641016, 10.873097826086964, 10.585291005291019, 10.365103626942988, 10.754543010752695, 10.53086842105262, 10.700347593582869, 10.364170984455976], "value": 10.585291005291019, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [12.299221311475389, 12.348395061728379, 12.003020000000019, 12.452676348547723, 12.715932203389826, 12.502937499999977, 12.100604838709666, 12.401260330578525, 12.248122448979595, 12.60949579831935, 12.397438016528927, 12.248755102040816], "value": 12.397438016528927, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.69798245614037, 11.561560693641628, 11.495545977011487, 11.76829411764702, 11.767558823529415, 11.697280701754389, 11.497701149425279, 11.768911764705905, 11.905446428571416, 12.123727272727278, 11.695672514619877, 11.90830357142858], "value": 11.767558823529415, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.196623134328357, 11.153178438661717, 11.237696629213497, 11.321584905660382, 11.498352490421484, 11.280582706766925, 11.152825278810411, 11.452061068702271, 11.583803088803096, 11.496149425287367, 11.408935361216713, 11.364450757575744], "value": 11.364450757575744, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.63976063829788, 10.87383152173911, 10.757876344086002, 10.934371584699482, 10.872228260869553, 10.695374331550822, 10.752607526881723, 11.115166666666685, 10.929453551912589, 10.934426229508198, 10.63930851063831, 10.929890710382503], "value": 10.87383152173911, "unit": "ms/frame"}]}, {"lowerIsBetter": true, "subtests": [{"name": "Mean tick time across 100 ticks: ", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [7.727950000000001, 6.5192499999999995, 6.48725, 6.6024, 6.674000000000001], "value": 6.5608249999999995, "unit": "ms"}], "extraOptions": ["e10s"], "name": "glvideo", "alertThreshold": 2.0}, {"lowerIsBetter": true, "subtests": [{"name": "", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [18290.655, 18753.620000000003, 19001.055, 19036.5, 18800.004999999997], "value": 18900.53, "unit": "ms"}], "extraOptions": ["e10s"], "name": "displaylist_mutate", "alertThreshold": 2.0}]} 13:28:14 INFO - Return code: 0 13:28:14 INFO - Validating PERFHERDER_DATA against /builds/slave/test/scripts/external_tools/performance-artifact-schema.json 13:28:14 INFO - # TBPL SUCCESS # 13:28:14 INFO - Running post-action listener: _package_coverage_data 13:28:14 INFO - Running post-action listener: _resource_record_post_action 13:28:14 INFO - [mozharness: 2017-11-09 21:28:14.970113Z] Finished run-tests step (success) 13:28:14 INFO - Running post-run listener: _resource_record_post_run 13:28:15 INFO - Total resource usage - Wall time: 705s; CPU: 35.0%; Read bytes: 17879040; Write bytes: 341635072; Read time: 4740; Write time: 421784 13:28:15 INFO - TinderboxPrint: CPU usage
34.8% 13:28:15 INFO - TinderboxPrint: I/O read bytes / time
17,879,040 / 4,740 13:28:15 INFO - TinderboxPrint: I/O write bytes / time
341,635,072 / 421,784 13:28:15 INFO - TinderboxPrint: CPU idle
3,614.8 (65.2%) 13:28:15 INFO - TinderboxPrint: CPU system
322.1 (5.8%) 13:28:15 INFO - TinderboxPrint: CPU user
1,584.8 (28.6%) 13:28:15 INFO - TinderboxPrint: Swap in / out
0 / 0 13:28:15 INFO - install - Wall time: 19s; CPU: 13.0%; Read bytes: 0; Write bytes: 5263360; Read time: 0; Write time: 1176 13:28:15 INFO - setup-mitmproxy - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0 13:28:15 INFO - run-tests - Wall time: 686s; CPU: 35.0%; Read bytes: 17846272; Write bytes: 306573312; Read time: 4616; Write time: 402828 13:28:15 INFO - Running post-run listener: _upload_blobber_files 13:28:15 INFO - Blob upload gear active. 13:28:15 INFO - Preparing to upload files from /builds/slave/test/build/blobber_upload_dir. 13:28:15 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 13:28:15 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'] 13:28:15 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 13:28:15 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:339: 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 13:28:15 INFO - SNIMissingWarning 13:28:15 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: 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 13:28:15 INFO - InsecurePlatformWarning 13:28:15 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/connection.py:344: 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.) 13:28:15 INFO - SubjectAltNameWarning 13:28:15 INFO - (blobuploader) - INFO - Open directory for files ... 13:28:15 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/perfherder-data.json ... 13:28:15 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 13:28:15 INFO - (blobuploader) - INFO - Uploading, attempt #1. 13:28:15 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: 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 13:28:15 INFO - InsecurePlatformWarning 13:28:15 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/connection.py:344: 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.) 13:28:15 INFO - SubjectAltNameWarning 13:28:16 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: 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 13:28:16 INFO - InsecurePlatformWarning 13:28:16 INFO - (blobuploader) - INFO - TinderboxPrint: perfherder-data.json: uploaded 13:28:16 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 13:28:16 INFO - (blobuploader) - INFO - Done attempting. 13:28:16 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-e10s_errorsummary.log ... 13:28:16 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 13:28:16 INFO - (blobuploader) - INFO - Uploading, attempt #1. 13:28:16 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: 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 13:28:16 INFO - InsecurePlatformWarning 13:28:16 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/connection.py:344: 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.) 13:28:16 INFO - SubjectAltNameWarning 13:28:17 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: 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 13:28:17 INFO - InsecurePlatformWarning 13:28:17 INFO - (blobuploader) - INFO - TinderboxPrint: g4-e10s_errorsummary.log: uploaded 13:28:17 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 13:28:17 INFO - (blobuploader) - INFO - Done attempting. 13:28:17 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/resource-usage.json ... 13:28:17 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 13:28:17 INFO - (blobuploader) - INFO - Uploading, attempt #1. 13:28:17 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: 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 13:28:17 INFO - InsecurePlatformWarning 13:28:17 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/connection.py:344: 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.) 13:28:17 INFO - SubjectAltNameWarning 13:28:19 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: 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 13:28:19 INFO - InsecurePlatformWarning 13:28:20 INFO - (blobuploader) - INFO - TinderboxPrint: resource-usage.json: uploaded 13:28:20 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 13:28:20 INFO - (blobuploader) - INFO - Done attempting. 13:28:20 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-e10s_raw.log ... 13:28:20 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 13:28:20 INFO - (blobuploader) - INFO - Uploading, attempt #1. 13:28:20 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: 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 13:28:20 INFO - InsecurePlatformWarning 13:28:20 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/connection.py:344: 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.) 13:28:20 INFO - SubjectAltNameWarning 13:28:20 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: 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 13:28:20 INFO - InsecurePlatformWarning 13:28:21 INFO - (blobuploader) - INFO - TinderboxPrint: g4-e10s_raw.log: uploaded 13:28:21 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 13:28:21 INFO - (blobuploader) - INFO - Done attempting. 13:28:21 INFO - (blobuploader) - INFO - Iteration through files over. 13:28:21 INFO - Return code: 0 13:28:21 INFO - rmtree: /builds/slave/test/build/uploaded_files.json 13:28:21 INFO - retry: Calling remove with args: ('/builds/slave/test/build/uploaded_files.json',), kwargs: {}, attempt #1 13:28:21 INFO - Setting buildbot property blobber_files to {"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/107aee7583197e656cf28103731030fa06bf0e010ef1e76f868eac36a010e551d37a1a9594fa7afab9c5b05b75a6320bd9051c2f3acf0c63507c784f3ce608fe", "g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/93d62243dc792b3db71a6b4bf238fecc3e0b7cac9ee23be809485344be0cc418b60c4518696f70abb72daa795cc4531506328a7cfe13120847a8baa7c034dbd5", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/2a448d3857b8ce3debf4e8d8e41d4e2f796e4959b3ce884aca243f8003bb70e1908214c51638d4be804e36336a58ca347062ead21a61e1b7cc1c75b97d971bed", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/8bbc465953c8c7fad3baf4162f99d79f0384b4200bcf289522084195315ff63081f099bdbd926c064c0890459b4aaa12a22cee9758eef9a16c58978795b7a444"} 13:28:21 INFO - Writing buildbot properties ['blobber_files'] to /builds/slave/test/properties/blobber_files 13:28:21 INFO - Writing to file /builds/slave/test/properties/blobber_files 13:28:21 INFO - Contents: 13:28:21 INFO - blobber_files:{"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/107aee7583197e656cf28103731030fa06bf0e010ef1e76f868eac36a010e551d37a1a9594fa7afab9c5b05b75a6320bd9051c2f3acf0c63507c784f3ce608fe", "g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/93d62243dc792b3db71a6b4bf238fecc3e0b7cac9ee23be809485344be0cc418b60c4518696f70abb72daa795cc4531506328a7cfe13120847a8baa7c034dbd5", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/2a448d3857b8ce3debf4e8d8e41d4e2f796e4959b3ce884aca243f8003bb70e1908214c51638d4be804e36336a58ca347062ead21a61e1b7cc1c75b97d971bed", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/8bbc465953c8c7fad3baf4162f99d79f0384b4200bcf289522084195315ff63081f099bdbd926c064c0890459b4aaa12a22cee9758eef9a16c58978795b7a444"} 13:28:21 INFO - Running post-run listener: copy_logs_to_upload_dir 13:28:21 INFO - Copying logs to upload dir... 13:28:21 INFO - mkdir: /builds/slave/test/build/upload/logs 13:28:21 INFO - Copying logs to upload dir... program finished with exit code 0 elapsedTime=766.454471 ========= master_lag: 0.03 ========= ========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 12 mins, 46 secs) (at 2017-11-09 13:28:21.521037) ========= ========= Started set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-11-09 13:28:21.524650) ========= 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=0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215 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/107aee7583197e656cf28103731030fa06bf0e010ef1e76f868eac36a010e551d37a1a9594fa7afab9c5b05b75a6320bd9051c2f3acf0c63507c784f3ce608fe", "g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/93d62243dc792b3db71a6b4bf238fecc3e0b7cac9ee23be809485344be0cc418b60c4518696f70abb72daa795cc4531506328a7cfe13120847a8baa7c034dbd5", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/2a448d3857b8ce3debf4e8d8e41d4e2f796e4959b3ce884aca243f8003bb70e1908214c51638d4be804e36336a58ca347062ead21a61e1b7cc1c75b97d971bed", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/8bbc465953c8c7fad3baf4162f99d79f0384b4200bcf289522084195315ff63081f099bdbd926c064c0890459b4aaa12a22cee9758eef9a16c58978795b7a444"} build_url:https://queue.taskcluster.net/v1/task/CuZ7j_4HT9Cb5o1Dot5Z3w/artifacts/public/build/target.tar.bz2 program finished with exit code 0 elapsedTime=0.011274 build_url: 'https://queue.taskcluster.net/v1/task/CuZ7j_4HT9Cb5o1Dot5Z3w/artifacts/public/build/target.tar.bz2' blobber_files: '{"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/107aee7583197e656cf28103731030fa06bf0e010ef1e76f868eac36a010e551d37a1a9594fa7afab9c5b05b75a6320bd9051c2f3acf0c63507c784f3ce608fe", "g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/93d62243dc792b3db71a6b4bf238fecc3e0b7cac9ee23be809485344be0cc418b60c4518696f70abb72daa795cc4531506328a7cfe13120847a8baa7c034dbd5", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/2a448d3857b8ce3debf4e8d8e41d4e2f796e4959b3ce884aca243f8003bb70e1908214c51638d4be804e36336a58ca347062ead21a61e1b7cc1c75b97d971bed", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/8bbc465953c8c7fad3baf4162f99d79f0384b4200bcf289522084195315ff63081f099bdbd926c064c0890459b4aaa12a22cee9758eef9a16c58978795b7a444"}' ========= master_lag: 0.02 ========= ========= Finished set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-11-09 13:28:21.557965) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-11-09 13:28:21.558324) ========= 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=0e2a256762fed810e2f0f810000001b3-1510262132.137285-1638594215 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.004409 ========= master_lag: 0.08 ========= ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-11-09 13:28:21.640433) ========= ========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2017-11-09 13:28:21.640748) ========= ========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2017-11-09 13:28:21.641062) ========= ========= Total master_lag: 0.23 =========