builder: mozilla-central_ubuntu64_hw_test-g4-stylo-disabled-e10s-pgo slave: talos-linux64-ix-032 starttime: 1510263421.4 results: success (0) revision: cbebb4f65eeaea4ac12c8e22383f0a739d2ae429 ========= Started set props: master (results: 0, elapsed: 0 secs) (at 2017-11-09 13:37:01.403133) ========= master: http://buildbot-master104.bb.releng.scl3.mozilla.com:8201/ ========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2017-11-09 13:37:01.403590) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-11-09 13:37:01.403863) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-11-09 13:37:01.422997) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-11-09 13:37:01.423402) ========= 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=745a4373a2a16df560f216e000000264-1510263420.469241-1453849038 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False --2017-11-09 13:37:01-- https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py Resolving hg.mozilla.org (hg.mozilla.org)... 63.245.215.25, 63.245.215.102 Connecting to hg.mozilla.org (hg.mozilla.org)|63.245.215.25|:443... connected. HTTP request sent, awaiting response... 200 Script output follows Length: 12179 (12K) [text/x-python] Saving to: `archiver_client.py' 0K .......... . 100% 221M=0s 2017-11-09 13:37:01 (221 MB/s) - `archiver_client.py' saved [12179/12179] program finished with exit code 0 elapsedTime=0.160251 ========= master_lag: 0.02 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-11-09 13:37:01.601184) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-11-09 13:37:01.601534) ========= 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=745a4373a2a16df560f216e000000264-1510263420.469241-1453849038 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.015385 ========= master_lag: 0.03 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-11-09 13:37:01.651613) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 2 secs) (at 2017-11-09 13:37:01.651961) ========= bash -c 'python archiver_client.py mozharness --repo mozilla-central --rev cbebb4f65eeaea4ac12c8e22383f0a739d2ae429 --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 cbebb4f65eeaea4ac12c8e22383f0a739d2ae429 --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=745a4373a2a16df560f216e000000264-1510263420.469241-1453849038 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 2017-11-09 13:37:01,703 truncating revision to first 12 chars 2017-11-09 13:37:01,703 Setting DEBUG logging. 2017-11-09 13:37:01,703 attempt 1/10 2017-11-09 13:37:01,703 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/mozilla-central/cbebb4f65eea?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness 2017-11-09 13:37:03,094 unpacking tar archive at: mozilla-central-cbebb4f65eea/testing/mozharness/ program finished with exit code 0 elapsedTime=2.002579 ========= master_lag: 0.02 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 2 secs) (at 2017-11-09 13:37:03.672899) ========= ========= Started set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-11-09 13:37:03.673272) ========= script_repo_revision: cbebb4f65eeaea4ac12c8e22383f0a739d2ae429 ========= Finished set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-11-09 13:37:03.673726) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-11-09 13:37:03.674140) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-11-09 13:37:03.690738) ========= ========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 10 mins, 59 secs) (at 2017-11-09 13:37:03.691571) ========= /tools/buildbot/bin/python scripts/scripts/talos_script.py --suite g4-stylo-disabled-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-stylo-disabled-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=745a4373a2a16df560f216e000000264-1510263420.469241-1453849038 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 13:37:03 INFO - MultiFileLogger online at 20171109 13:37:03 in /builds/slave/test 13:37:03 INFO - Run as scripts/scripts/talos_script.py --suite g4-stylo-disabled-e10s --add-option --webServer,localhost --branch-name Firefox --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Firefox 13:37:03 INFO - Dumping config to /builds/slave/test/logs/localconfig.json. 13:37:03 INFO - {'append_to_log': False, 13:37:03 INFO - 'base_work_dir': '/builds/slave/test', 13:37:03 INFO - 'blob_upload_branch': 'Firefox', 13:37:03 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt', 13:37:03 INFO - 'branch': 'Firefox', 13:37:03 INFO - 'buildbot_json_path': 'buildprops.json', 13:37:03 INFO - 'code_coverage': False, 13:37:03 INFO - 'config_files': ('talos/linux_config.py',), 13:37:03 INFO - 'default_actions': ('clobber', 13:37:03 INFO - 'read-buildbot-config', 13:37:03 INFO - 'download-and-extract', 13:37:03 INFO - 'populate-webroot', 13:37:03 INFO - 'create-virtualenv', 13:37:03 INFO - 'install', 13:37:03 INFO - 'setup-mitmproxy', 13:37:03 INFO - 'run-tests'), 13:37:03 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 13:37:03 INFO - 'disable_ccov_upload': False, 13:37:03 INFO - 'disable_stylo': False, 13:37:03 INFO - 'download_minidump_stackwalk': True, 13:37:03 INFO - 'download_symbols': 'ondemand', 13:37:03 INFO - 'e10s': False, 13:37:03 INFO - 'enable_stylo': False, 13:37:03 INFO - 'enable_webrender': False, 13:37:03 INFO - 'exes': {'tooltool.py': '/tools/tooltool.py'}, 13:37:03 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 13:37:03 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 13:37:03 INFO - 'gecko_profile': False, 13:37:03 INFO - 'gecko_profile_interval': 0, 13:37:03 INFO - 'installer_path': 'installer.exe', 13:37:03 INFO - 'jsd_code_coverage': False, 13:37:03 INFO - 'log_level': 'info', 13:37:03 INFO - 'log_name': 'talos', 13:37:03 INFO - 'log_to_console': True, 13:37:03 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk', 13:37:03 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest', 13:37:03 INFO - 'opt_config_files': (), 13:37:03 INFO - 'pip_index': False, 13:37:03 INFO - 'suite': 'g4-stylo-disabled-e10s', 13:37:03 INFO - 'system_bits': '32', 13:37:03 INFO - 'talos_extra_options': ('--webServer', 'localhost'), 13:37:03 INFO - 'title': 'talos-linux64-ix-032', 13:37:03 INFO - 'tooltool_cache': '/builds/tooltool_cache', 13:37:03 INFO - 'use_talos_json': True, 13:37:03 INFO - 'verify': 'False', 13:37:03 INFO - 'virtualenv_path': '/builds/slave/test/build/venv', 13:37:03 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 13:37:03 INFO - 'work_dir': 'build'} 13:37:03 INFO - [mozharness: 2017-11-09 21:37:03.885221Z] Running clobber step. 13:37:03 INFO - Running pre-action listener: _resource_record_pre_action 13:37:03 INFO - Running main action method: clobber 13:37:03 INFO - rmtree: /builds/slave/test/build 13:37:03 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1 13:37:05 INFO - Running post-action listener: _resource_record_post_action 13:37:05 INFO - [mozharness: 2017-11-09 21:37:05.486888Z] Finished clobber step (success) 13:37:05 INFO - [mozharness: 2017-11-09 21:37:05.486986Z] Running read-buildbot-config step. 13:37:05 INFO - Running pre-action listener: _resource_record_pre_action 13:37:05 INFO - Running main action method: read_buildbot_config 13:37:05 INFO - Using buildbot properties: 13:37:05 INFO - { 13:37:05 INFO - "project": "", 13:37:05 INFO - "product": "firefox", 13:37:05 INFO - "who": "apavel@mozilla.com", 13:37:05 INFO - "installer_path": "public/build/target.tar.bz2", 13:37:05 INFO - "builddir": "mozilla-central_ubuntu64_hw_test-g4-stylo-disabled-e10s", 13:37:05 INFO - "repository": "https://hg.mozilla.org/mozilla-central", 13:37:05 INFO - "buildername": "Ubuntu HW 12.04 x64 mozilla-central pgo talos g4-stylo-disabled-e10s", 13:37:05 INFO - "stage_platform": "linux64-pgo", 13:37:05 INFO - "basedir": "/builds/slave/test", 13:37:05 INFO - "buildnumber": 62, 13:37:05 INFO - "platform": "ubuntu64_hw", 13:37:05 INFO - "master": "http://buildbot-master104.bb.releng.scl3.mozilla.com:8201/", 13:37:05 INFO - "slavebuilddir": "test", 13:37:05 INFO - "taskId": "aPPxx0HkRjegvc0YW7EBDg", 13:37:05 INFO - "branch": "mozilla-central", 13:37:05 INFO - "script_repo_revision": "production", 13:37:05 INFO - "revision": "cbebb4f65eeaea4ac12c8e22383f0a739d2ae429", 13:37:05 INFO - "slavename": "talos-linux64-ix-032", 13:37:05 INFO - "repo_path": "mozilla-central" 13:37:05 INFO - } 13:37:05 INFO - Finding installer, test and symbols from parent task. 13:37:05 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/aPPxx0HkRjegvc0YW7EBDg'}, attempt #1 13:37:05 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/aPPxx0HkRjegvc0YW7EBDg'}, attempt #1 13:37:06 INFO - Task dependencies: TXEoGj7dQvmJaiobeEs1dw 13:37:06 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/TXEoGj7dQvmJaiobeEs1dw'}, attempt #1 13:37:06 INFO - Set installer_url: https://queue.taskcluster.net/v1/task/TXEoGj7dQvmJaiobeEs1dw/artifacts/public/build/target.tar.bz2 13:37:06 INFO - Set test_packages_url: https://queue.taskcluster.net/v1/task/TXEoGj7dQvmJaiobeEs1dw/artifacts/public/build/target.test_packages.json 13:37:06 INFO - Set symbols_url: https://queue.taskcluster.net/v1/task/TXEoGj7dQvmJaiobeEs1dw/artifacts/public/build/target.crashreporter-symbols.zip 13:37:06 INFO - Running post-action listener: _resource_record_post_action 13:37:06 INFO - [mozharness: 2017-11-09 21:37:06.835835Z] Finished read-buildbot-config step (success) 13:37:06 INFO - [mozharness: 2017-11-09 21:37:06.836096Z] Running download-and-extract step. 13:37:06 INFO - Running pre-action listener: _resource_record_pre_action 13:37:06 INFO - Running main action method: download_and_extract 13:37:06 INFO - mkdir: /builds/slave/test/build/tests 13:37:06 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:37:06 INFO - trying https://queue.taskcluster.net/v1/task/TXEoGj7dQvmJaiobeEs1dw/artifacts/public/build/target.test_packages.json 13:37:06 INFO - Downloading https://queue.taskcluster.net/v1/task/TXEoGj7dQvmJaiobeEs1dw/artifacts/public/build/target.test_packages.json to /builds/slave/test/build/target.test_packages.json 13:37:06 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/TXEoGj7dQvmJaiobeEs1dw/artifacts/public/build/target.test_packages.json', 'file_name': '/builds/slave/test/build/target.test_packages.json'}, attempt #1 13:37:07 INFO - Downloaded 989 bytes. 13:37:07 INFO - Reading from file /builds/slave/test/build/target.test_packages.json 13:37:07 INFO - Using the following test package requirements: 13:37:07 INFO - {u'awsy': [u'target.common.tests.zip', u'target.awsy.tests.zip'], 13:37:07 INFO - u'common': [u'target.common.tests.zip'], 13:37:07 INFO - u'cppunittest': [u'target.common.tests.zip', u'target.cppunittest.tests.zip'], 13:37:07 INFO - u'gtest': [u'target.common.tests.zip', u'target.gtest.tests.zip'], 13:37:07 INFO - u'jittest': [u'target.common.tests.zip', u'target.jsshell.zip'], 13:37:07 INFO - u'mochitest': [u'target.common.tests.zip', u'target.mochitest.tests.zip'], 13:37:07 INFO - u'mozbase': [u'target.common.tests.zip'], 13:37:07 INFO - u'reftest': [u'target.common.tests.zip', u'target.reftest.tests.zip'], 13:37:07 INFO - u'talos': [u'target.common.tests.zip', u'target.talos.tests.zip'], 13:37:07 INFO - u'web-platform': [u'target.common.tests.zip', 13:37:07 INFO - u'target.web-platform.tests.tar.gz'], 13:37:07 INFO - u'xpcshell': [u'target.common.tests.zip', u'target.xpcshell.tests.zip']} 13:37:07 INFO - Downloading packages: [u'target.common.tests.zip', u'target.talos.tests.zip'] for test suite categories: ['common', 'talos'] 13:37:07 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/TXEoGj7dQvmJaiobeEs1dw/artifacts/public/build/target.common.tests.zip 13:37:07 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/TXEoGj7dQvmJaiobeEs1dw/artifacts/public/build/target.common.tests.zip'}, attempt #1 13:37:07 INFO - Fetch https://queue.taskcluster.net/v1/task/TXEoGj7dQvmJaiobeEs1dw/artifacts/public/build/target.common.tests.zip into memory 13:37:08 INFO - Content-Length response header: 58648677 13:37:08 INFO - Bytes received: 58648677 13:37:19 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/TXEoGj7dQvmJaiobeEs1dw/artifacts/public/build/target.talos.tests.zip 13:37:19 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/TXEoGj7dQvmJaiobeEs1dw/artifacts/public/build/target.talos.tests.zip'}, attempt #1 13:37:19 INFO - Fetch https://queue.taskcluster.net/v1/task/TXEoGj7dQvmJaiobeEs1dw/artifacts/public/build/target.talos.tests.zip into memory 13:37:20 INFO - Content-Length response header: 18771918 13:37:20 INFO - Bytes received: 18771918 13:37:21 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:37:21 INFO - trying https://queue.taskcluster.net/v1/task/TXEoGj7dQvmJaiobeEs1dw/artifacts/public/build/target.tar.bz2 13:37:21 INFO - Downloading https://queue.taskcluster.net/v1/task/TXEoGj7dQvmJaiobeEs1dw/artifacts/public/build/target.tar.bz2 to /builds/slave/test/build/target.tar.bz2 13:37:21 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/TXEoGj7dQvmJaiobeEs1dw/artifacts/public/build/target.tar.bz2', 'file_name': '/builds/slave/test/build/target.tar.bz2'}, attempt #1 13:37:22 INFO - Downloaded 63328053 bytes. 13:37:22 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/TXEoGj7dQvmJaiobeEs1dw/artifacts/public/build/target.tar.bz2 13:37:22 INFO - mkdir: /builds/slave/test/properties 13:37:22 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url 13:37:22 INFO - Writing to file /builds/slave/test/properties/build_url 13:37:22 INFO - Contents: 13:37:22 INFO - build_url:https://queue.taskcluster.net/v1/task/TXEoGj7dQvmJaiobeEs1dw/artifacts/public/build/target.tar.bz2 13:37:22 INFO - Running post-action listener: _resource_record_post_action 13:37:22 INFO - Running post-action listener: find_tests_for_verification 13:37:22 INFO - Running post-action listener: set_extra_try_arguments 13:37:22 INFO - [mozharness: 2017-11-09 21:37:22.646323Z] Finished download-and-extract step (success) 13:37:22 INFO - [mozharness: 2017-11-09 21:37:22.646418Z] Running populate-webroot step. 13:37:22 INFO - Running pre-action listener: _resource_record_pre_action 13:37:22 INFO - Running main action method: populate_webroot 13:37:22 INFO - {'suites': {'chromez-e10s': {'tests': ['tresize', 'tcanvasmark']}, 13:37:22 INFO - 'chromez-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:37:22 INFO - 'tests': ['tresize', 13:37:22 INFO - 'tcanvasmark']}, 13:37:22 INFO - 'dromaeojs-e10s': {'tests': ['dromaeo_css', 'kraken']}, 13:37:22 INFO - 'dromaeojs-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:37:22 INFO - 'tests': ['dromaeo_css', 13:37:22 INFO - 'kraken']}, 13:37:22 INFO - 'g1-e10s': {'pagesets_name': 'tp5n.zip', 13:37:22 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 13:37:22 INFO - 'g1-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 13:37:22 INFO - 'talos_options': ['--disable-stylo'], 13:37:22 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 13:37:22 INFO - 'g2-e10s': {'pagesets_name': 'tp5n.zip', 13:37:22 INFO - 'tests': ['damp', 'tps']}, 13:37:22 INFO - 'g2-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 13:37:22 INFO - 'talos_options': ['--disable-stylo'], 13:37:22 INFO - 'tests': ['damp', 'tps']}, 13:37:22 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']}, 13:37:22 INFO - 'g3-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:37:22 INFO - 'tests': ['dromaeo_dom']}, 13:37:22 INFO - 'g4-e10s': {'tests': ['basic_compositor_video', 13:37:22 INFO - 'glvideo', 13:37:22 INFO - 'displaylist_mutate']}, 13:37:22 INFO - 'g4-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:37:22 INFO - 'tests': ['basic_compositor_video', 13:37:22 INFO - 'glvideo']}, 13:37:22 INFO - 'g5-e10s': {'pagesets_name': 'tp5n.zip', 13:37:22 INFO - 'tests': ['ts_paint_webext', 'tp5o_webext']}, 13:37:22 INFO - 'g5-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 13:37:22 INFO - 'talos_options': ['--disable-stylo'], 13:37:22 INFO - 'tests': ['ts_paint_webext', 13:37:22 INFO - 'tp5o_webext']}, 13:37:22 INFO - 'h1-e10s': {'tests': ['ts_paint_heavy']}, 13:37:22 INFO - 'h2-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 13:37:22 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 13:37:22 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 13:37:22 INFO - 'talos_options': ['--mitmproxy', 13:37:22 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 13:37:22 INFO - '--firstNonBlankPaint'], 13:37:22 INFO - 'tests': ['tp6_google_heavy', 13:37:22 INFO - 'tp6_youtube_heavy', 13:37:22 INFO - 'tp6_amazon_heavy', 13:37:22 INFO - 'tp6_facebook_heavy']}, 13:37:22 INFO - 'other-e10s': {'tests': ['a11yr', 13:37:22 INFO - 'ts_paint', 13:37:22 INFO - 'tpaint', 13:37:22 INFO - 'sessionrestore', 13:37:22 INFO - 'sessionrestore_many_windows', 13:37:22 INFO - 'sessionrestore_no_auto_restore', 13:37:22 INFO - 'tabpaint', 13:37:22 INFO - 'cpstartup']}, 13:37:22 INFO - 'other-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:37:22 INFO - 'tests': ['a11yr', 13:37:22 INFO - 'ts_paint', 13:37:22 INFO - 'tpaint', 13:37:22 INFO - 'sessionrestore', 13:37:22 INFO - 'sessionrestore_many_windows', 13:37:22 INFO - 'sessionrestore_no_auto_restore', 13:37:22 INFO - 'tabpaint', 13:37:22 INFO - 'cpstartup']}, 13:37:22 INFO - 'perf-reftest-e10s': {'tests': ['perf_reftest']}, 13:37:22 INFO - 'perf-reftest-singletons-e10s': {'tests': ['perf_reftest_singletons']}, 13:37:22 INFO - 'perf-reftest-singletons-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:37:22 INFO - 'tests': ['perf_reftest_singletons']}, 13:37:22 INFO - 'perf-reftest-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:37:22 INFO - 'tests': ['perf_reftest']}, 13:37:22 INFO - 'speedometer-e10s': {'tests': ['speedometer']}, 13:37:22 INFO - 'speedometer-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:37:22 INFO - 'tests': ['speedometer']}, 13:37:22 INFO - 'svgr-e10s': {'tests': ['tsvgx', 13:37:22 INFO - 'tsvgr_opacity', 13:37:22 INFO - 'tart', 13:37:22 INFO - 'tscrollx', 13:37:22 INFO - 'tsvg_static']}, 13:37:22 INFO - 'svgr-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:37:22 INFO - 'tests': ['tsvgx', 13:37:22 INFO - 'tsvgr_opacity', 13:37:22 INFO - 'tart', 13:37:22 INFO - 'tscrollx', 13:37:22 INFO - 'tsvg_static']}, 13:37:22 INFO - 'tp5o-e10s': {'pagesets_name': 'tp5n.zip', 'tests': ['tp5o']}, 13:37:22 INFO - 'tp5o-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 13:37:22 INFO - 'talos_options': ['--disable-stylo'], 13:37:22 INFO - 'tests': ['tp5o']}, 13:37:22 INFO - 'tp6-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 13:37:22 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 13:37:22 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 13:37:22 INFO - 'talos_options': ['--mitmproxy', 13:37:22 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 13:37:22 INFO - '--firstNonBlankPaint'], 13:37:22 INFO - 'tests': ['tp6_google', 13:37:22 INFO - 'tp6_youtube', 13:37:22 INFO - 'tp6_amazon', 13:37:22 INFO - 'tp6_facebook']}, 13:37:22 INFO - 'tp6-stylo-disabled-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 13:37:22 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 13:37:22 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 13:37:22 INFO - 'talos_options': ['--disable-stylo', 13:37:22 INFO - '--mitmproxy', 13:37:22 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 13:37:22 INFO - '--firstNonBlankPaint'], 13:37:22 INFO - 'tests': ['tp6_google', 13:37:22 INFO - 'tp6_youtube', 13:37:22 INFO - 'tp6_amazon', 13:37:22 INFO - 'tp6_facebook']}, 13:37:22 INFO - 'tp6-stylo-threads-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 13:37:22 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 13:37:22 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 13:37:22 INFO - 'talos_options': ['--stylo-threads=1', 13:37:22 INFO - '--mitmproxy', 13:37:22 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 13:37:22 INFO - '--firstNonBlankPaint'], 13:37:22 INFO - 'tests': ['tp6_google', 13:37:22 INFO - 'tp6_youtube', 13:37:22 INFO - 'tp6_amazon', 13:37:22 INFO - 'tp6_facebook']}, 13:37:22 INFO - 'xperf-e10s': {'pagesets_name': 'tp5n.zip', 13:37:22 INFO - 'talos_options': ['--xperf_path', 13:37:22 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 13:37:22 INFO - 'tests': ['tp5n']}, 13:37:22 INFO - 'xperf-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 13:37:22 INFO - 'talos_options': ['--disable-stylo', 13:37:22 INFO - '--xperf_path', 13:37:22 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 13:37:22 INFO - 'tests': ['tp5n']}}} 13:37:22 INFO - Running post-action listener: _resource_record_post_action 13:37:22 INFO - [mozharness: 2017-11-09 21:37:22.670695Z] Finished populate-webroot step (success) 13:37:22 INFO - [mozharness: 2017-11-09 21:37:22.670788Z] Running create-virtualenv step. 13:37:22 INFO - Running pre-action listener: _resource_record_pre_action 13:37:22 INFO - Running main action method: create_virtualenv 13:37:22 INFO - Creating virtualenv /builds/slave/test/build/venv 13:37:22 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:37:22 INFO - Copy/paste: /tools/buildbot/bin/python /builds/slave/test/scripts/external_tools/virtualenv/virtualenv.py --always-copy /builds/slave/test/build/venv 13:37:22 INFO - Using partial env: {'VIRTUALENV_NO_DOWNLOAD': '1'} 13:37:23 INFO - Using real prefix '/usr' 13:37:23 INFO - New python executable in /builds/slave/test/build/venv/bin/python 13:37:23 INFO - Overwriting /builds/slave/test/build/venv/lib/python2.7/distutils/__init__.py with new content 13:37:26 INFO - Installing setuptools, pip, wheel...done. 13:37:26 INFO - Return code: 0 13:37:26 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv 13:37:26 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:37:26 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:37:26 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:37:26 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:37:26 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 0x213d2d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2315a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x24b8930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x24b5ad0>, '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 0x24b69d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x24b6e60>, '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': '745a4373a2a16df560f216e000000264-1510263420.469241-1453849038', '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:37:26 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:37:26 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:37:26 INFO - Using env: {'DISPLAY': ':0', 13:37:26 INFO - 'HOME': '/home/cltbld', 13:37:26 INFO - 'LANG': 'en_US.UTF-8', 13:37:26 INFO - 'LANGUAGE': 'en_US:en', 13:37:26 INFO - 'LOGNAME': 'cltbld', 13:37:26 INFO - 'MAIL': '/var/mail/cltbld', 13:37:26 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:37:26 INFO - 'MOZ_NO_REMOTE': '1', 13:37:26 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:37:26 INFO - 'NO_EM_RESTART': '1', 13:37:26 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:37:26 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:37:26 INFO - 'PWD': '/builds/slave/test', 13:37:26 INFO - 'SHELL': '/bin/bash', 13:37:26 INFO - 'SHLVL': '1', 13:37:26 INFO - 'TERM': 'linux', 13:37:26 INFO - 'TMOUT': '86400', 13:37:26 INFO - 'USER': 'cltbld', 13:37:26 INFO - 'XDG_SESSION_COOKIE': '745a4373a2a16df560f216e000000264-1510263420.469241-1453849038', 13:37:26 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:37:26 INFO - '_': '/tools/buildbot/bin/python'} 13:37:26 INFO - Ignoring indexes: https://pypi.python.org/simple 13:37:26 INFO - Requirement already satisfied (use --upgrade to upgrade): pip>=1.5 in ./venv/lib/python2.7/site-packages 13:37:26 INFO - Return code: 0 13:37:27 INFO - Installing psutil>=3.1.1 into virtualenv /builds/slave/test/build/venv 13:37:27 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:37:27 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:37:27 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:37:27 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:37:27 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 0x213d2d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2315a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x24b8930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x24b5ad0>, '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 0x24b69d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x24b6e60>, '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': '745a4373a2a16df560f216e000000264-1510263420.469241-1453849038', '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:37:27 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:37:27 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:37:27 INFO - Using env: {'DISPLAY': ':0', 13:37:27 INFO - 'HOME': '/home/cltbld', 13:37:27 INFO - 'LANG': 'en_US.UTF-8', 13:37:27 INFO - 'LANGUAGE': 'en_US:en', 13:37:27 INFO - 'LOGNAME': 'cltbld', 13:37:27 INFO - 'MAIL': '/var/mail/cltbld', 13:37:27 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:37:27 INFO - 'MOZ_NO_REMOTE': '1', 13:37:27 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:37:27 INFO - 'NO_EM_RESTART': '1', 13:37:27 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:37:27 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:37:27 INFO - 'PWD': '/builds/slave/test', 13:37:27 INFO - 'SHELL': '/bin/bash', 13:37:27 INFO - 'SHLVL': '1', 13:37:27 INFO - 'TERM': 'linux', 13:37:27 INFO - 'TMOUT': '86400', 13:37:27 INFO - 'USER': 'cltbld', 13:37:27 INFO - 'XDG_SESSION_COOKIE': '745a4373a2a16df560f216e000000264-1510263420.469241-1453849038', 13:37:27 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:37:27 INFO - '_': '/tools/buildbot/bin/python'} 13:37:27 INFO - Ignoring indexes: https://pypi.python.org/simple 13:37:27 INFO - Collecting psutil>=3.1.1 13:37:28 INFO - Installing collected packages: psutil 13:37:28 INFO - Successfully installed psutil-3.1.1 13:37:28 INFO - Return code: 0 13:37:28 INFO - Installing mozsystemmonitor==0.3 into virtualenv /builds/slave/test/build/venv 13:37:28 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:37:28 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:37:28 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:37:28 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:37:28 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'mozsystemmonitor==0.3']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x213d2d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2315a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x24b8930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x24b5ad0>, '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 0x24b69d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x24b6e60>, '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': '745a4373a2a16df560f216e000000264-1510263420.469241-1453849038', '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:37:28 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'mozsystemmonitor==0.3'] in /builds/slave/test/build 13:37:28 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org mozsystemmonitor==0.3 13:37:28 INFO - Using env: {'DISPLAY': ':0', 13:37:28 INFO - 'HOME': '/home/cltbld', 13:37:28 INFO - 'LANG': 'en_US.UTF-8', 13:37:28 INFO - 'LANGUAGE': 'en_US:en', 13:37:28 INFO - 'LOGNAME': 'cltbld', 13:37:28 INFO - 'MAIL': '/var/mail/cltbld', 13:37:28 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:37:28 INFO - 'MOZ_NO_REMOTE': '1', 13:37:28 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:37:28 INFO - 'NO_EM_RESTART': '1', 13:37:28 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:37:28 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:37:28 INFO - 'PWD': '/builds/slave/test', 13:37:28 INFO - 'SHELL': '/bin/bash', 13:37:28 INFO - 'SHLVL': '1', 13:37:28 INFO - 'TERM': 'linux', 13:37:28 INFO - 'TMOUT': '86400', 13:37:28 INFO - 'USER': 'cltbld', 13:37:28 INFO - 'XDG_SESSION_COOKIE': '745a4373a2a16df560f216e000000264-1510263420.469241-1453849038', 13:37:28 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:37:28 INFO - '_': '/tools/buildbot/bin/python'} 13:37:29 INFO - Ignoring indexes: https://pypi.python.org/simple 13:37:29 INFO - Collecting mozsystemmonitor==0.3 13:37:30 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.3) 13:37:30 INFO - Installing collected packages: mozsystemmonitor 13:37:30 INFO - Successfully installed mozsystemmonitor-0.3 13:37:30 INFO - Return code: 0 13:37:30 INFO - Installing jsonschema==2.5.1 into virtualenv /builds/slave/test/build/venv 13:37:30 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:37:30 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:37:30 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:37:30 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:37:30 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', '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 0x213d2d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2315a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x24b8930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x24b5ad0>, '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 0x24b69d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x24b6e60>, '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': '745a4373a2a16df560f216e000000264-1510263420.469241-1453849038', '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:37:30 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'jsonschema==2.5.1'] in /builds/slave/test/build 13:37:30 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org jsonschema==2.5.1 13:37:30 INFO - Using env: {'DISPLAY': ':0', 13:37:30 INFO - 'HOME': '/home/cltbld', 13:37:30 INFO - 'LANG': 'en_US.UTF-8', 13:37:30 INFO - 'LANGUAGE': 'en_US:en', 13:37:30 INFO - 'LOGNAME': 'cltbld', 13:37:30 INFO - 'MAIL': '/var/mail/cltbld', 13:37:30 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:37:30 INFO - 'MOZ_NO_REMOTE': '1', 13:37:30 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:37:30 INFO - 'NO_EM_RESTART': '1', 13:37:30 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:37:30 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:37:30 INFO - 'PWD': '/builds/slave/test', 13:37:30 INFO - 'SHELL': '/bin/bash', 13:37:30 INFO - 'SHLVL': '1', 13:37:30 INFO - 'TERM': 'linux', 13:37:30 INFO - 'TMOUT': '86400', 13:37:30 INFO - 'USER': 'cltbld', 13:37:30 INFO - 'XDG_SESSION_COOKIE': '745a4373a2a16df560f216e000000264-1510263420.469241-1453849038', 13:37:30 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:37:30 INFO - '_': '/tools/buildbot/bin/python'} 13:37:30 INFO - Ignoring indexes: https://pypi.python.org/simple 13:37:30 INFO - Collecting jsonschema==2.5.1 13:37:31 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/jsonschema-2.5.1-py2.py3-none-any.whl 13:37:31 INFO - Collecting functools32; python_version == "2.7" (from jsonschema==2.5.1) 13:37:32 INFO - Installing collected packages: functools32, jsonschema 13:37:33 INFO - Successfully installed functools32-3.2.3.post2 jsonschema-2.5.1 13:37:33 INFO - Return code: 0 13:37:33 INFO - Installing functools32==3.2.3-2 into virtualenv /builds/slave/test/build/venv 13:37:33 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:37:33 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:37:33 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:37:33 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:37:33 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 0x213d2d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2315a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x24b8930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x24b5ad0>, '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 0x24b69d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x24b6e60>, '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': '745a4373a2a16df560f216e000000264-1510263420.469241-1453849038', '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:37:33 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:37:33 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:37:33 INFO - Using env: {'DISPLAY': ':0', 13:37:33 INFO - 'HOME': '/home/cltbld', 13:37:33 INFO - 'LANG': 'en_US.UTF-8', 13:37:33 INFO - 'LANGUAGE': 'en_US:en', 13:37:33 INFO - 'LOGNAME': 'cltbld', 13:37:33 INFO - 'MAIL': '/var/mail/cltbld', 13:37:33 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:37:33 INFO - 'MOZ_NO_REMOTE': '1', 13:37:33 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:37:33 INFO - 'NO_EM_RESTART': '1', 13:37:33 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:37:33 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:37:33 INFO - 'PWD': '/builds/slave/test', 13:37:33 INFO - 'SHELL': '/bin/bash', 13:37:33 INFO - 'SHLVL': '1', 13:37:33 INFO - 'TERM': 'linux', 13:37:33 INFO - 'TMOUT': '86400', 13:37:33 INFO - 'USER': 'cltbld', 13:37:33 INFO - 'XDG_SESSION_COOKIE': '745a4373a2a16df560f216e000000264-1510263420.469241-1453849038', 13:37:33 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:37:33 INFO - '_': '/tools/buildbot/bin/python'} 13:37:34 INFO - Ignoring indexes: https://pypi.python.org/simple 13:37:34 INFO - Requirement already satisfied (use --upgrade to upgrade): functools32==3.2.3-2 in ./venv/lib/python2.7/site-packages 13:37:34 INFO - Return code: 0 13:37:34 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv 13:37:34 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:37:34 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:37:34 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:37:34 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:37:34 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', '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 0x213d2d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2315a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x24b8930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x24b5ad0>, '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 0x24b69d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x24b6e60>, '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': '745a4373a2a16df560f216e000000264-1510263420.469241-1453849038', '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:37:34 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'blobuploader==1.2.4'] in /builds/slave/test/build 13:37:34 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org blobuploader==1.2.4 13:37:34 INFO - Using env: {'DISPLAY': ':0', 13:37:34 INFO - 'HOME': '/home/cltbld', 13:37:34 INFO - 'LANG': 'en_US.UTF-8', 13:37:34 INFO - 'LANGUAGE': 'en_US:en', 13:37:34 INFO - 'LOGNAME': 'cltbld', 13:37:34 INFO - 'MAIL': '/var/mail/cltbld', 13:37:34 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:37:34 INFO - 'MOZ_NO_REMOTE': '1', 13:37:34 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:37:34 INFO - 'NO_EM_RESTART': '1', 13:37:34 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:37:34 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:37:34 INFO - 'PWD': '/builds/slave/test', 13:37:34 INFO - 'SHELL': '/bin/bash', 13:37:34 INFO - 'SHLVL': '1', 13:37:34 INFO - 'TERM': 'linux', 13:37:34 INFO - 'TMOUT': '86400', 13:37:34 INFO - 'USER': 'cltbld', 13:37:34 INFO - 'XDG_SESSION_COOKIE': '745a4373a2a16df560f216e000000264-1510263420.469241-1453849038', 13:37:34 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:37:34 INFO - '_': '/tools/buildbot/bin/python'} 13:37:34 INFO - Ignoring indexes: https://pypi.python.org/simple 13:37:34 INFO - Collecting blobuploader==1.2.4 13:37:35 INFO - Collecting requests==1.2.3. (from blobuploader==1.2.4) 13:37:36 INFO - Collecting docopt==0.6.1 (from blobuploader==1.2.4) 13:37:37 INFO - Installing collected packages: requests, docopt, blobuploader 13:37:38 INFO - Successfully installed blobuploader-1.2.4 docopt-0.6.1 requests-1.2.3 13:37:38 INFO - Return code: 0 13:37:38 INFO - Installing None into virtualenv /builds/slave/test/build/venv 13:37:38 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:37:38 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:37:38 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:37:38 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:37:38 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 0x213d2d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2315a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x24b8930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x24b5ad0>, '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 0x24b69d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x24b6e60>, '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': '745a4373a2a16df560f216e000000264-1510263420.469241-1453849038', '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:37:38 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:37:38 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:37:38 INFO - Using env: {'DISPLAY': ':0', 13:37:38 INFO - 'HOME': '/home/cltbld', 13:37:38 INFO - 'LANG': 'en_US.UTF-8', 13:37:38 INFO - 'LANGUAGE': 'en_US:en', 13:37:38 INFO - 'LOGNAME': 'cltbld', 13:37:38 INFO - 'MAIL': '/var/mail/cltbld', 13:37:38 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:37:38 INFO - 'MOZ_NO_REMOTE': '1', 13:37:38 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:37:38 INFO - 'NO_EM_RESTART': '1', 13:37:38 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:37:38 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:37:38 INFO - 'PWD': '/builds/slave/test', 13:37:38 INFO - 'SHELL': '/bin/bash', 13:37:38 INFO - 'SHLVL': '1', 13:37:38 INFO - 'TERM': 'linux', 13:37:38 INFO - 'TMOUT': '86400', 13:37:38 INFO - 'USER': 'cltbld', 13:37:38 INFO - 'XDG_SESSION_COOKIE': '745a4373a2a16df560f216e000000264-1510263420.469241-1453849038', 13:37:38 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:37:38 INFO - '_': '/tools/buildbot/bin/python'} 13:37:38 INFO - Ignoring indexes: https://pypi.python.org/simple 13:37:38 INFO - Processing /builds/slave/test/build/tests/mozbase/manifestparser 13:37:38 INFO - Processing /builds/slave/test/build/tests/mozbase/mozcrash 13:37:39 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdebug 13:37:39 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdevice 13:37:39 INFO - Processing /builds/slave/test/build/tests/mozbase/mozfile 13:37:39 INFO - Processing /builds/slave/test/build/tests/mozbase/mozhttpd 13:37:39 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinfo 13:37:40 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinstall 13:37:40 INFO - Processing /builds/slave/test/build/tests/mozbase/mozleak 13:37:40 INFO - Processing /builds/slave/test/build/tests/mozbase/mozlog 13:37:40 INFO - Processing /builds/slave/test/build/tests/mozbase/moznetwork 13:37:40 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprocess 13:37:40 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprofile 13:37:41 INFO - Processing /builds/slave/test/build/tests/mozbase/mozrunner 13:37:41 INFO - Processing /builds/slave/test/build/tests/mozbase/mozscreenshot 13:37:41 INFO - Processing /builds/slave/test/build/tests/mozbase/moztest 13:37:41 INFO - Processing /builds/slave/test/build/tests/mozbase/mozversion 13:37:41 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion 13:37:41 INFO - Running setup.py install for manifestparser: started 13:37:42 INFO - Running setup.py install for manifestparser: finished with status 'done' 13:37:42 INFO - Running setup.py install for mozcrash: started 13:37:42 INFO - Running setup.py install for mozcrash: finished with status 'done' 13:37:42 INFO - Running setup.py install for mozdebug: started 13:37:42 INFO - Running setup.py install for mozdebug: finished with status 'done' 13:37:42 INFO - Running setup.py install for mozdevice: started 13:37:42 INFO - Running setup.py install for mozdevice: finished with status 'done' 13:37:42 INFO - Running setup.py install for mozfile: started 13:37:42 INFO - Running setup.py install for mozfile: finished with status 'done' 13:37:42 INFO - Running setup.py install for mozhttpd: started 13:37:43 INFO - Running setup.py install for mozhttpd: finished with status 'done' 13:37:43 INFO - Running setup.py install for mozinfo: started 13:37:43 INFO - Running setup.py install for mozinfo: finished with status 'done' 13:37:43 INFO - Running setup.py install for mozInstall: started 13:37:43 INFO - Running setup.py install for mozInstall: finished with status 'done' 13:37:43 INFO - Running setup.py install for mozleak: started 13:37:43 INFO - Running setup.py install for mozleak: finished with status 'done' 13:37:43 INFO - Running setup.py install for mozlog: started 13:37:44 INFO - Running setup.py install for mozlog: finished with status 'done' 13:37:44 INFO - Running setup.py install for moznetwork: started 13:37:44 INFO - Running setup.py install for moznetwork: finished with status 'done' 13:37:44 INFO - Running setup.py install for mozprocess: started 13:37:44 INFO - Running setup.py install for mozprocess: finished with status 'done' 13:37:44 INFO - Running setup.py install for mozprofile: started 13:37:44 INFO - Running setup.py install for mozprofile: finished with status 'done' 13:37:44 INFO - Running setup.py install for mozrunner: started 13:37:45 INFO - Running setup.py install for mozrunner: finished with status 'done' 13:37:45 INFO - Running setup.py install for mozscreenshot: started 13:37:45 INFO - Running setup.py install for mozscreenshot: finished with status 'done' 13:37:45 INFO - Running setup.py install for moztest: started 13:37:45 INFO - Running setup.py install for moztest: finished with status 'done' 13:37:45 INFO - Running setup.py install for mozversion: started 13:37:45 INFO - Running setup.py install for mozversion: finished with status 'done' 13:37:45 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:37:45 INFO - Return code: 0 13:37:45 INFO - Installing None into virtualenv /builds/slave/test/build/venv 13:37:45 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:37:45 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:37:45 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:37:45 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:37:45 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 0x213d2d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2315a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x24b8930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x24b5ad0>, '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 0x24b69d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x24b6e60>, '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': '745a4373a2a16df560f216e000000264-1510263420.469241-1453849038', '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:37:45 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:37:45 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:37:45 INFO - Using env: {'DISPLAY': ':0', 13:37:45 INFO - 'HOME': '/home/cltbld', 13:37:45 INFO - 'LANG': 'en_US.UTF-8', 13:37:45 INFO - 'LANGUAGE': 'en_US:en', 13:37:45 INFO - 'LOGNAME': 'cltbld', 13:37:45 INFO - 'MAIL': '/var/mail/cltbld', 13:37:45 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:37:45 INFO - 'MOZ_NO_REMOTE': '1', 13:37:45 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:37:45 INFO - 'NO_EM_RESTART': '1', 13:37:45 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:37:45 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:37:45 INFO - 'PWD': '/builds/slave/test', 13:37:45 INFO - 'SHELL': '/bin/bash', 13:37:45 INFO - 'SHLVL': '1', 13:37:45 INFO - 'TERM': 'linux', 13:37:45 INFO - 'TMOUT': '86400', 13:37:45 INFO - 'USER': 'cltbld', 13:37:45 INFO - 'XDG_SESSION_COOKIE': '745a4373a2a16df560f216e000000264-1510263420.469241-1453849038', 13:37:45 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:37:45 INFO - '_': '/tools/buildbot/bin/python'} 13:37:46 INFO - Ignoring indexes: https://pypi.python.org/simple 13:37:46 INFO - Processing /builds/slave/test/build/tests/mozbase/manifestparser 13:37:46 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:37:46 INFO - Processing /builds/slave/test/build/tests/mozbase/mozcrash 13:37:46 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:37:46 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdebug 13:37:47 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:37:47 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdevice 13:37:47 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:37:47 INFO - Processing /builds/slave/test/build/tests/mozbase/mozfile 13:37:47 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:37:47 INFO - Processing /builds/slave/test/build/tests/mozbase/mozhttpd 13:37:47 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:37:47 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinfo 13:37:47 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:37:47 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinstall 13:37:48 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:37:48 INFO - Processing /builds/slave/test/build/tests/mozbase/mozleak 13:37:48 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:37:48 INFO - Processing /builds/slave/test/build/tests/mozbase/mozlog 13:37:48 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:37:48 INFO - Processing /builds/slave/test/build/tests/mozbase/moznetwork 13:37:48 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:37:48 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprocess 13:37:48 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:37:48 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprofile 13:37:49 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:37:49 INFO - Processing /builds/slave/test/build/tests/mozbase/mozrunner 13:37:49 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:37:49 INFO - Processing /builds/slave/test/build/tests/mozbase/mozscreenshot 13:37:49 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:37:49 INFO - Processing /builds/slave/test/build/tests/mozbase/moztest 13:37:49 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:37:49 INFO - Processing /builds/slave/test/build/tests/mozbase/mozversion 13:37:49 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:37:49 INFO - Collecting six>=1.10.0 (from manifestparser==1.2->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 1)) 13:37:50 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/six-1.10.0-py2.py3-none-any.whl 13:37:50 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:37:50 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:37:50 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:37:50 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:37:50 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:37:50 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:37:50 INFO - Collecting blessings>=1.3 (from mozlog==3.5->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 13:37:52 INFO - Installing collected packages: six, blessings 13:37:52 INFO - Successfully installed blessings-1.6 six-1.10.0 13:37:52 INFO - Return code: 0 13:37:52 INFO - Done creating virtualenv /builds/slave/test/build/venv. 13:37:52 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 13:37:52 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 13:37:52 INFO - Reading from file tmpfile_stdout 13:37:52 INFO - Reading from file tmpfile_stderr 13:37:52 INFO - Current package versions: 13:37:52 INFO - blessings == 1.6 13:37:52 INFO - blobuploader == 1.2.4 13:37:52 INFO - docopt == 0.6.1 13:37:52 INFO - functools32 == 3.2.3.post2 13:37:52 INFO - jsonschema == 2.5.1 13:37:52 INFO - manifestparser == 1.2 13:37:52 INFO - mozInstall == 1.14 13:37:52 INFO - mozcrash == 1.0 13:37:52 INFO - mozdebug == 0.1 13:37:52 INFO - mozdevice == 0.51 13:37:52 INFO - mozfile == 1.2 13:37:52 INFO - mozhttpd == 0.7 13:37:52 INFO - mozinfo == 0.10 13:37:52 INFO - mozleak == 0.1 13:37:52 INFO - mozlog == 3.5 13:37:52 INFO - moznetwork == 0.27 13:37:52 INFO - mozprocess == 0.25 13:37:52 INFO - mozprofile == 0.29 13:37:52 INFO - mozrunner == 6.13 13:37:52 INFO - mozscreenshot == 0.1 13:37:52 INFO - mozsystemmonitor == 0.3 13:37:52 INFO - moztest == 0.8 13:37:52 INFO - mozversion == 1.4 13:37:52 INFO - psutil == 3.1.1 13:37:52 INFO - requests == 1.2.3 13:37:52 INFO - six == 1.10.0 13:37:52 INFO - Installing None into virtualenv /builds/slave/test/build/venv 13:37:52 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:37:52 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:37:52 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:37:52 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:37:52 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 0x213d2d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2315a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x24b8930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x24b5ad0>, '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 0x24b69d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x24b6e60>, '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': '745a4373a2a16df560f216e000000264-1510263420.469241-1453849038', '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:37:52 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:37:52 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:37:52 INFO - Using env: {'DISPLAY': ':0', 13:37:52 INFO - 'HOME': '/home/cltbld', 13:37:52 INFO - 'LANG': 'en_US.UTF-8', 13:37:52 INFO - 'LANGUAGE': 'en_US:en', 13:37:52 INFO - 'LOGNAME': 'cltbld', 13:37:52 INFO - 'MAIL': '/var/mail/cltbld', 13:37:52 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:37:52 INFO - 'MOZ_NO_REMOTE': '1', 13:37:52 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:37:52 INFO - 'NO_EM_RESTART': '1', 13:37:52 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:37:52 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:37:52 INFO - 'PWD': '/builds/slave/test', 13:37:52 INFO - 'SHELL': '/bin/bash', 13:37:52 INFO - 'SHLVL': '1', 13:37:52 INFO - 'TERM': 'linux', 13:37:52 INFO - 'TMOUT': '86400', 13:37:52 INFO - 'USER': 'cltbld', 13:37:52 INFO - 'XDG_SESSION_COOKIE': '745a4373a2a16df560f216e000000264-1510263420.469241-1453849038', 13:37:52 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:37:52 INFO - '_': '/tools/buildbot/bin/python'} 13:37:53 INFO - Ignoring indexes: https://pypi.python.org/simple 13:37:53 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:37:53 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:37:53 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:37:53 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:37:53 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:37:53 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:37:53 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:37:53 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:37:53 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:37:53 INFO - Collecting simplejson>=2.1.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 10)) 13:37:54 INFO - Collecting requests>=2.9.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 13:37:55 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/requests-2.18.3-py2.py3-none-any.whl (88kB) 13:37:56 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:37:56 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:37:56 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:37:56 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:37:57 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/chardet-3.0.4-py2.py3-none-any.whl (133kB) 13:37:57 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:37:58 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/urllib3-1.22-py2.py3-none-any.whl (132kB) 13:37:58 INFO - Collecting certifi>=2017.4.17 (from requests>=2.9.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 13:37:59 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/certifi-2017.7.27.1-py2.py3-none-any.whl (349kB) 13:37:59 INFO - Collecting idna<2.6,>=2.5 (from requests>=2.9.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 13:38:00 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/idna-2.5-py2.py3-none-any.whl (55kB) 13:38:00 INFO - Installing collected packages: simplejson, chardet, urllib3, certifi, idna, requests 13:38:00 INFO - Found existing installation: requests 1.2.3 13:38:00 INFO - Uninstalling requests-1.2.3: 13:38:00 INFO - Successfully uninstalled requests-1.2.3 13:38:00 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:38:00 INFO - Return code: 0 13:38:00 INFO - Installing jsonschema into virtualenv /builds/slave/test/build/venv 13:38: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:38:00 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:38: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:38:00 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:38: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']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x213d2d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2315a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x24b8930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x24b5ad0>, '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 0x24b69d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x24b6e60>, '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': '745a4373a2a16df560f216e000000264-1510263420.469241-1453849038', '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:38: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'] in /builds/slave/test/build 13:38: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 13:38:00 INFO - Using env: {'DISPLAY': ':0', 13:38:00 INFO - 'HOME': '/home/cltbld', 13:38:00 INFO - 'LANG': 'en_US.UTF-8', 13:38:00 INFO - 'LANGUAGE': 'en_US:en', 13:38:00 INFO - 'LOGNAME': 'cltbld', 13:38:00 INFO - 'MAIL': '/var/mail/cltbld', 13:38:00 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:38:00 INFO - 'MOZ_NO_REMOTE': '1', 13:38:00 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:38:00 INFO - 'NO_EM_RESTART': '1', 13:38:00 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:38:00 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:38:00 INFO - 'PWD': '/builds/slave/test', 13:38:00 INFO - 'SHELL': '/bin/bash', 13:38:00 INFO - 'SHLVL': '1', 13:38:00 INFO - 'TERM': 'linux', 13:38:00 INFO - 'TMOUT': '86400', 13:38:00 INFO - 'USER': 'cltbld', 13:38:00 INFO - 'XDG_SESSION_COOKIE': '745a4373a2a16df560f216e000000264-1510263420.469241-1453849038', 13:38:00 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:38:00 INFO - '_': '/tools/buildbot/bin/python'} 13:38:01 INFO - Ignoring indexes: https://pypi.python.org/simple 13:38:01 INFO - Requirement already satisfied (use --upgrade to upgrade): jsonschema in ./venv/lib/python2.7/site-packages 13:38:01 INFO - Requirement already satisfied (use --upgrade to upgrade): functools32; python_version == "2.7" in ./venv/lib/python2.7/site-packages (from jsonschema) 13:38:01 INFO - Return code: 0 13:38:01 INFO - Running post-action listener: _resource_record_post_action 13:38:01 INFO - Running post-action listener: _start_resource_monitoring 13:38:01 INFO - Starting resource monitoring. 13:38:01 INFO - [mozharness: 2017-11-09 21:38:01.238335Z] Finished create-virtualenv step (success) 13:38:01 INFO - [mozharness: 2017-11-09 21:38:01.238847Z] Running install step. 13:38:01 INFO - Running pre-action listener: _resource_record_pre_action 13:38:01 INFO - Running main action method: install 13:38:01 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 13:38:01 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 13:38:01 INFO - Reading from file tmpfile_stdout 13:38:01 INFO - Reading from file tmpfile_stderr 13:38:01 INFO - Detecting whether we're running mozinstall >=1.0... 13:38:01 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h'] 13:38:01 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h 13:38:01 INFO - Reading from file tmpfile_stdout 13:38:01 INFO - Output received: 13:38:01 INFO - Usage: mozinstall [options] installer 13:38:01 INFO - Options: 13:38:01 INFO - -h, --help show this help message and exit 13:38:01 INFO - -d DEST, --destination=DEST 13:38:01 INFO - Directory to install application into. [default: 13:38:01 INFO - "/builds/slave/test"] 13:38:01 INFO - --app=APP Application being installed. [default: firefox] 13:38:01 INFO - mkdir: /builds/slave/test/build/application 13:38:01 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:38:01 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall /builds/slave/test/build/target.tar.bz2 --destination /builds/slave/test/build/application 13:38:20 INFO - Reading from file tmpfile_stdout 13:38:20 INFO - Output received: 13:38:20 INFO - /builds/slave/test/build/application/firefox/firefox 13:38:20 INFO - Running post-action listener: _resource_record_post_action 13:38:20 INFO - [mozharness: 2017-11-09 21:38:20.058831Z] Finished install step (success) 13:38:20 INFO - [mozharness: 2017-11-09 21:38:20.058975Z] Running setup-mitmproxy step. 13:38:20 INFO - Running pre-action listener: _resource_record_pre_action 13:38:20 INFO - Running main action method: setup_mitmproxy 13:38:20 INFO - Skipping: mitmproxy is not required 13:38:20 INFO - Running post-action listener: _resource_record_post_action 13:38:20 INFO - [mozharness: 2017-11-09 21:38:20.059658Z] Finished setup-mitmproxy step (success) 13:38:20 INFO - [mozharness: 2017-11-09 21:38:20.059789Z] Running run-tests step. 13:38:20 INFO - Running pre-action listener: _resource_record_pre_action 13:38:20 INFO - Running pre-action listener: _set_gcov_prefix 13:38:20 INFO - Running main action method: run_tests 13:38:20 WARNING - Try message not found. 13:38:20 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version'] 13:38:20 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version 13:38:20 INFO - Python 2.7.3 13:38:20 INFO - Return code: 0 13:38:20 INFO - grabbing minidump binary from tooltool 13:38:20 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:38:20 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 0x24b5ad0>, '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 0x24b69d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x24b6e60>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1 13:38:20 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:38:20 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:38:20 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:38:20 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache 13:38:20 INFO - Return code: 0 13:38:20 INFO - Chmoding /builds/slave/test/build/linux64-minidump_stackwalk to 0755 13:38:20 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir 13:38:20 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir 13:38:20 INFO - ENV: RUST_BACKTRACE is now full 13:38:20 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/linux64-minidump_stackwalk 13:38:20 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir 13:38:20 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--branchName', 'Firefox', '--suite', 'g4-stylo-disabled-e10s', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/TXEoGj7dQvmJaiobeEs1dw/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-032', '--webServer', 'localhost', '--log-tbpl-level=debug', '--log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_errorsummary.log', '--log-raw=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_raw.log'] in /builds/slave/test/build 13:38:20 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/tests/talos/talos/run_tests.py --branchName Firefox --suite g4-stylo-disabled-e10s --executablePath /builds/slave/test/build/application/firefox/firefox --symbolsPath https://queue.taskcluster.net/v1/task/TXEoGj7dQvmJaiobeEs1dw/artifacts/public/build/target.crashreporter-symbols.zip --title talos-linux64-ix-032 --webServer localhost --log-tbpl-level=debug --log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_errorsummary.log --log-raw=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_raw.log 13:38:20 INFO - Using env: {'DISPLAY': ':0', 13:38:20 INFO - 'HOME': '/home/cltbld', 13:38:20 INFO - 'LANG': 'en_US.UTF-8', 13:38:20 INFO - 'LANGUAGE': 'en_US:en', 13:38:20 INFO - 'LOGNAME': 'cltbld', 13:38:20 INFO - 'MAIL': '/var/mail/cltbld', 13:38:20 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 13:38:20 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 13:38:20 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:38:20 INFO - 'MOZ_NO_REMOTE': '1', 13:38:20 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 13:38:20 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:38:20 INFO - 'NO_EM_RESTART': '1', 13:38:20 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:38:20 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:38:20 INFO - 'PWD': '/builds/slave/test', 13:38:20 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 13:38:20 INFO - 'RUST_BACKTRACE': 'full', 13:38:20 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 13:38:20 INFO - 'SHELL': '/bin/bash', 13:38:20 INFO - 'SHLVL': '1', 13:38:20 INFO - 'TERM': 'linux', 13:38:20 INFO - 'TMOUT': '86400', 13:38:20 INFO - 'USER': 'cltbld', 13:38:20 INFO - 'XDG_SESSION_COOKIE': '745a4373a2a16df560f216e000000264-1510263420.469241-1453849038', 13:38:20 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:38:20 INFO - '_': '/tools/buildbot/bin/python'} 13:38:20 INFO - Calling ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--branchName', 'Firefox', '--suite', 'g4-stylo-disabled-e10s', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/TXEoGj7dQvmJaiobeEs1dw/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-032', '--webServer', 'localhost', '--log-tbpl-level=debug', '--log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_errorsummary.log', '--log-raw=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_raw.log'] with output_timeout 3600 13:38:20 INFO - mozversion application_buildid: 20171109201038 13:38:20 INFO - mozversion application_changeset: cbebb4f65eeaea4ac12c8e22383f0a739d2ae429 13:38:20 INFO - mozversion application_display_name: Nightly 13:38:20 INFO - mozversion application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384} 13:38:20 INFO - mozversion application_name: Firefox 13:38:20 INFO - mozversion application_remotingname: firefox 13:38:20 INFO - mozversion application_repository: https://hg.mozilla.org/mozilla-central 13:38:20 INFO - mozversion application_vendor: Mozilla 13:38:20 INFO - mozversion application_version: 58.0a1 13:38:20 INFO - mozversion platform_buildid: 20171109201038 13:38:20 INFO - mozversion platform_changeset: cbebb4f65eeaea4ac12c8e22383f0a739d2ae429 13:38:20 INFO - mozversion platform_repository: https://hg.mozilla.org/mozilla-central 13:38:20 INFO - mozversion platform_version: 58.0a1 13:38:20 INFO - using testdate: 1510263500 13:38:20 INFO - actual date: 1510263500 13:38:20 INFO - starting webserver on 'localhost:42803' 13:38:20 INFO - SUITE-START | Running 2 tests 13:38:20 INFO - TEST-START | basic_compositor_video 13:38:20 INFO - Initialising browser for basic_compositor_video test... 13:38:20 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:42803/getInfo.html -profile /tmp/tmpDQhuY8/profile 13:38:20 INFO - TEST-INFO | started process 11695 (/builds/slave/test/build/application/firefox/firefox http://localhost:42803/getInfo.html) 13:38:26 INFO - TEST-INFO | 11695: exit 0 13:38:26 INFO - Browser initialized. 13:38:26 INFO - Running cycle 1/1 for basic_compositor_video test... 13:38:26 INFO - Using env: {'DISPLAY': ':0', 13:38:26 INFO - 'HOME': '/home/cltbld', 13:38:26 INFO - 'JSGC_DISABLE_POISONING': '1', 13:38:26 INFO - 'LANG': 'en_US.UTF-8', 13:38:26 INFO - 'LANGUAGE': 'en_US:en', 13:38:26 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 13:38:26 INFO - 'LOGNAME': 'cltbld', 13:38:26 INFO - 'MAIL': '/var/mail/cltbld', 13:38:26 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 13:38:26 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 13:38:26 INFO - 'MOZ_CRASHREPORTER': '1', 13:38:26 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:38:26 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 13:38:26 INFO - 'MOZ_NO_REMOTE': '1', 13:38:26 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 13:38:26 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:38:26 INFO - 'NO_EM_RESTART': '1', 13:38:26 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:38:26 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:38:26 INFO - 'PWD': '/builds/slave/test', 13:38:26 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 13:38:26 INFO - 'RUST_BACKTRACE': 'full', 13:38:26 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 13:38:26 INFO - 'SHELL': '/bin/bash', 13:38:26 INFO - 'SHLVL': '1', 13:38:26 INFO - 'STYLO_FORCE_DISABLED': '1', 13:38:26 INFO - 'TERM': 'linux', 13:38:26 INFO - 'TMOUT': '86400', 13:38:26 INFO - 'USER': 'cltbld', 13:38:26 INFO - 'XDG_SESSION_COOKIE': '745a4373a2a16df560f216e000000264-1510263420.469241-1453849038', 13:38:26 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:38:26 INFO - '_': '/tools/buildbot/bin/python'} 13:38:26 INFO - TEST-INFO | started process 11970 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDQhuY8/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/video/video.manifest.develop -tpnoisy -tpcycles 1 -tppagecycles 12) 13:38:26 INFO - PID 11970 | 13:38:26 INFO - PID 11970 | (/builds/slave/test/build/application/firefox/firefox:12021): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 13:38:26 INFO - PID 11970 | 13:39:13 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1_startup = 1.677873113471213 ms/frame 13:39:13 INFO - PID 11970 | 13:39:13 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6697662771285473 ms/frame 13:39:13 INFO - PID 11970 | 13:39:13 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.750717619603267 ms/frame 13:39:13 INFO - PID 11970 | 13:39:13 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7142502142245077 ms/frame 13:39:13 INFO - PID 11970 | 13:39:13 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_2_startup = 3.9855976095617516 ms/frame 13:39:13 INFO - PID 11970 | 13:39:13 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.073625254582484 ms/frame 13:39:13 INFO - PID 11970 | 13:39:13 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1_startup = 3.4487298850574697 ms/frame 13:39:13 INFO - PID 11970 | 13:39:13 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1_inclip = 3.344590301003348 ms/frame 13:39:13 INFO - PID 11970 | 13:39:13 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.30223498233216 ms/frame 13:39:13 INFO - PID 11970 | 13:39:13 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.589273743016757 ms/frame 13:39:13 INFO - PID 11970 | 13:39:13 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_2_startup = 10.566373239436615 ms/frame 13:39:13 INFO - PID 11970 | 13:39:13 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_2_inclip = 9.854950738916257 ms/frame 13:39:13 INFO - PID 11970 | 13:39:13 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.11433333333333 ms/frame 13:39:13 INFO - PID 11970 | 13:39:13 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.755860215053744 ms/frame 13:39:13 INFO - PID 11970 | 13:39:13 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.609621848739511 ms/frame 13:39:13 INFO - PID 11970 | 13:39:13 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.978473053892209 ms/frame 13:39:13 INFO - PID 11970 | 13:39:13 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.40910646387833 ms/frame 13:39:13 INFO - PID 11970 | 13:39:13 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.054033149171264 ms/frame 13:39:13 INFO - PID 11970 | 13:39:13 INFO - PID 11970 | Cycle 1(1): loaded http://localhost:42803/tests/video/video_playback.html (next: http://localhost:42803/tests/video/video_playback.html) 13:39:59 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6779026845637586 ms/frame 13:39:59 INFO - PID 11970 | 13:39:59 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6674916666666668 ms/frame 13:39:59 INFO - PID 11970 | 13:39:59 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7236444572085008 ms/frame 13:39:59 INFO - PID 11970 | 13:39:59 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7013180272108852 ms/frame 13:39:59 INFO - PID 11970 | 13:39:59 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_2_startup = 3.9435282522996076 ms/frame 13:39:59 INFO - PID 11970 | 13:39:59 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.098913934426227 ms/frame 13:39:59 INFO - PID 11970 | 13:39:59 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1_startup = 3.5171101992965994 ms/frame 13:39:59 INFO - PID 11970 | 13:39:59 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1_inclip = 3.436434707903782 ms/frame 13:39:59 INFO - PID 11970 | 13:39:59 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.703868821292777 ms/frame 13:39:59 INFO - PID 11970 | 13:39:59 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.169315245478031 ms/frame 13:39:59 INFO - PID 11970 | 13:39:59 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_2_startup = 10.41819444444444 ms/frame 13:39:59 INFO - PID 11970 | 13:39:59 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_2_inclip = 10.000575000000008 ms/frame 13:39:59 INFO - PID 11970 | 13:39:59 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.99003663003664 ms/frame 13:39:59 INFO - PID 11970 | 13:39:59 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.47371727748689 ms/frame 13:39:59 INFO - PID 11970 | 13:39:59 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.661518987341767 ms/frame 13:39:59 INFO - PID 11970 | 13:39:59 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.904374999999986 ms/frame 13:39:59 INFO - PID 11970 | 13:39:59 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.495919540229876 ms/frame 13:39:59 INFO - PID 11970 | 13:39:59 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.050690607734822 ms/frame 13:39:59 INFO - PID 11970 | 13:39:59 INFO - PID 11970 | Cycle 1(2): loaded http://localhost:42803/tests/video/video_playback.html (next: http://localhost:42803/tests/video/video_playback.html) 13:40:45 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6799440089585667 ms/frame 13:40:45 INFO - PID 11970 | 13:40:45 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.668277731442869 ms/frame 13:40:45 INFO - PID 11970 | 13:40:45 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7629259694477086 ms/frame 13:40:45 INFO - PID 11970 | 13:40:45 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7131806506849314 ms/frame 13:40:45 INFO - PID 11970 | 13:40:45 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_2_startup = 4.033393817204303 ms/frame 13:40:45 INFO - PID 11970 | 13:40:45 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.5660160427807486 ms/frame 13:40:45 INFO - PID 11970 | 13:40:45 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1_startup = 3.437657502863689 ms/frame 13:40:45 INFO - PID 11970 | 13:40:45 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3565520134228146 ms/frame 13:40:45 INFO - PID 11970 | 13:40:45 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.537167896678961 ms/frame 13:40:45 INFO - PID 11970 | 13:40:45 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.556875000000006 ms/frame 13:40:45 INFO - PID 11970 | 13:40:45 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_2_startup = 10.718035714285712 ms/frame 13:40:45 INFO - PID 11970 | 13:40:45 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_2_inclip = 10.10209595959596 ms/frame 13:40:45 INFO - PID 11970 | 13:40:45 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.198917910447767 ms/frame 13:40:45 INFO - PID 11970 | 13:40:45 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.53160526315788 ms/frame 13:40:45 INFO - PID 11970 | 13:40:45 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.501416666666682 ms/frame 13:40:45 INFO - PID 11970 | 13:40:45 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.697426900584764 ms/frame 13:40:45 INFO - PID 11970 | 13:40:45 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.630329457364342 ms/frame 13:40:45 INFO - PID 11970 | 13:40:45 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.175418994413416 ms/frame 13:40:45 INFO - PID 11970 | 13:40:45 INFO - PID 11970 | Cycle 1(3): loaded http://localhost:42803/tests/video/video_playback.html (next: http://localhost:42803/tests/video/video_playback.html) 13:41:32 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1_startup = 1.683773849607183 ms/frame 13:41:32 INFO - PID 11970 | 13:41:32 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6660491257285597 ms/frame 13:41:32 INFO - PID 11970 | 13:41:32 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.74768782760629 ms/frame 13:41:32 INFO - PID 11970 | 13:41:32 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7168240343347643 ms/frame 13:41:32 INFO - PID 11970 | 13:41:32 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_2_startup = 4.099713114754098 ms/frame 13:41:32 INFO - PID 11970 | 13:41:32 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.193846960167715 ms/frame 13:41:32 INFO - PID 11970 | 13:41:32 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1_startup = 3.5473995271867618 ms/frame 13:41:32 INFO - PID 11970 | 13:41:32 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4258561643835628 ms/frame 13:41:32 INFO - PID 11970 | 13:41:32 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.597388059701494 ms/frame 13:41:32 INFO - PID 11970 | 13:41:32 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.52653314917127 ms/frame 13:41:32 INFO - PID 11970 | 13:41:32 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_2_startup = 10.49115384615385 ms/frame 13:41:32 INFO - PID 11970 | 13:41:32 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_2_inclip = 10.003575000000001 ms/frame 13:41:32 INFO - PID 11970 | 13:41:32 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.951350364963497 ms/frame 13:41:32 INFO - PID 11970 | 13:41:32 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.695802139037422 ms/frame 13:41:32 INFO - PID 11970 | 13:41:32 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.605273109243699 ms/frame 13:41:32 INFO - PID 11970 | 13:41:32 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.907261904761938 ms/frame 13:41:32 INFO - PID 11970 | 13:41:32 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.583648648648651 ms/frame 13:41:32 INFO - PID 11970 | 13:41:32 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.053287292817702 ms/frame 13:41:32 INFO - PID 11970 | 13:41:32 INFO - PID 11970 | Cycle 1(4): loaded http://localhost:42803/tests/video/video_playback.html (next: http://localhost:42803/tests/video/video_playback.html) 13:42:18 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6915727170236752 ms/frame 13:42:18 INFO - PID 11970 | 13:42:18 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.667383333333333 ms/frame 13:42:18 INFO - PID 11970 | 13:42:18 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7334546504910455 ms/frame 13:42:18 INFO - PID 11970 | 13:42:18 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7170729613733908 ms/frame 13:42:18 INFO - PID 11970 | 13:42:18 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_2_startup = 4.138151724137931 ms/frame 13:42:18 INFO - PID 11970 | 13:42:18 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.149657676348548 ms/frame 13:42:18 INFO - PID 11970 | 13:42:18 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1_startup = 3.5551658767772505 ms/frame 13:42:18 INFO - PID 11970 | 13:42:18 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1_inclip = 3.5030035026269704 ms/frame 13:42:18 INFO - PID 11970 | 13:42:18 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.7049524714828905 ms/frame 13:42:18 INFO - PID 11970 | 13:42:18 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.571782729805015 ms/frame 13:42:18 INFO - PID 11970 | 13:42:18 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_2_startup = 10.20749999999999 ms/frame 13:42:18 INFO - PID 11970 | 13:42:18 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_2_inclip = 10.003075000000008 ms/frame 13:42:18 INFO - PID 11970 | 13:42:18 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.112925925925918 ms/frame 13:42:18 INFO - PID 11970 | 13:42:18 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.697005347593603 ms/frame 13:42:18 INFO - PID 11970 | 13:42:18 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.146275303643744 ms/frame 13:42:18 INFO - PID 11970 | 13:42:18 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.904642857142832 ms/frame 13:42:18 INFO - PID 11970 | 13:42:18 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.587065637065649 ms/frame 13:42:18 INFO - PID 11970 | 13:42:18 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.930928961748638 ms/frame 13:42:18 INFO - PID 11970 | 13:42:18 INFO - PID 11970 | Cycle 1(5): loaded http://localhost:42803/tests/video/video_playback.html (next: http://localhost:42803/tests/video/video_playback.html) 13:43:04 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6803079507278837 ms/frame 13:43:04 INFO - PID 11970 | 13:43:04 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6711528822055142 ms/frame 13:43:04 INFO - PID 11970 | 13:43:04 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7794928825622778 ms/frame 13:43:04 INFO - PID 11970 | 13:43:04 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7303892733564021 ms/frame 13:43:04 INFO - PID 11970 | 13:43:04 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_2_startup = 4.133181818181819 ms/frame 13:43:04 INFO - PID 11970 | 13:43:04 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.033407258064516 ms/frame 13:43:04 INFO - PID 11970 | 13:43:04 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1_startup = 3.4170842824601375 ms/frame 13:43:04 INFO - PID 11970 | 13:43:04 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3453344481605325 ms/frame 13:43:04 INFO - PID 11970 | 13:43:04 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.587001862197395 ms/frame 13:43:04 INFO - PID 11970 | 13:43:04 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.449822888283377 ms/frame 13:43:04 INFO - PID 11970 | 13:43:04 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_2_startup = 10.680391459074741 ms/frame 13:43:04 INFO - PID 11970 | 13:43:04 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_2_inclip = 10.256641025641017 ms/frame 13:43:04 INFO - PID 11970 | 13:43:04 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.155390334572488 ms/frame 13:43:04 INFO - PID 11970 | 13:43:04 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.585555555555585 ms/frame 13:43:04 INFO - PID 11970 | 13:43:04 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.771446808510643 ms/frame 13:43:04 INFO - PID 11970 | 13:43:04 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.976826347305417 ms/frame 13:43:04 INFO - PID 11970 | 13:43:04 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.540442307692306 ms/frame 13:43:04 INFO - PID 11970 | 13:43:04 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.990851648351644 ms/frame 13:43:04 INFO - PID 11970 | 13:43:04 INFO - PID 11970 | Cycle 1(6): loaded http://localhost:42803/tests/video/video_playback.html (next: http://localhost:42803/tests/video/video_playback.html) 13:43:50 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1_startup = 1.677096143096702 ms/frame 13:43:50 INFO - PID 11970 | 13:43:50 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.668240200166806 ms/frame 13:43:50 INFO - PID 11970 | 13:43:50 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7397101449275363 ms/frame 13:43:50 INFO - PID 11970 | 13:43:50 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.732268398268398 ms/frame 13:43:50 INFO - PID 11970 | 13:43:50 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_2_startup = 4.076216032608698 ms/frame 13:43:50 INFO - PID 11970 | 13:43:50 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.9451972386587775 ms/frame 13:43:50 INFO - PID 11970 | 13:43:50 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1_startup = 3.41433447098976 ms/frame 13:43:50 INFO - PID 11970 | 13:43:50 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1_inclip = 3.356375838926177 ms/frame 13:43:50 INFO - PID 11970 | 13:43:50 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.629906191369609 ms/frame 13:43:50 INFO - PID 11970 | 13:43:50 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.479712328767117 ms/frame 13:43:50 INFO - PID 11970 | 13:43:50 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_2_startup = 10.312766323024054 ms/frame 13:43:50 INFO - PID 11970 | 13:43:50 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_2_inclip = 9.904034653465354 ms/frame 13:43:50 INFO - PID 11970 | 13:43:50 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.873242753623199 ms/frame 13:43:50 INFO - PID 11970 | 13:43:50 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.585608465608468 ms/frame 13:43:50 INFO - PID 11970 | 13:43:50 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.450082987551871 ms/frame 13:43:50 INFO - PID 11970 | 13:43:50 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.839112426035532 ms/frame 13:43:50 INFO - PID 11970 | 13:43:50 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.58332046332047 ms/frame 13:43:50 INFO - PID 11970 | 13:43:50 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.051381215469629 ms/frame 13:43:50 INFO - PID 11970 | 13:43:50 INFO - PID 11970 | Cycle 1(7): loaded http://localhost:42803/tests/video/video_playback.html (next: http://localhost:42803/tests/video/video_playback.html) 13:44:36 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6810616246498598 ms/frame 13:44:36 INFO - PID 11970 | 13:44:36 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6669000000000003 ms/frame 13:44:36 INFO - PID 11970 | 13:44:36 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.722726750861079 ms/frame 13:44:36 INFO - PID 11970 | 13:44:36 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.6896706081081085 ms/frame 13:44:36 INFO - PID 11970 | 13:44:36 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_2_startup = 3.979316976127322 ms/frame 13:44:36 INFO - PID 11970 | 13:44:36 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.167916666666664 ms/frame 13:44:36 INFO - PID 11970 | 13:44:36 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1_startup = 3.421271379703535 ms/frame 13:44:36 INFO - PID 11970 | 13:44:36 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3576174496644287 ms/frame 13:44:36 INFO - PID 11970 | 13:44:36 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.650263653483988 ms/frame 13:44:36 INFO - PID 11970 | 13:44:36 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.668654390934854 ms/frame 13:44:36 INFO - PID 11970 | 13:44:36 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_2_startup = 10.565669014084513 ms/frame 13:44:36 INFO - PID 11970 | 13:44:36 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_2_inclip = 9.758121951219517 ms/frame 13:44:36 INFO - PID 11970 | 13:44:36 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.32466037735849 ms/frame 13:44:36 INFO - PID 11970 | 13:44:36 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.696256684492003 ms/frame 13:44:36 INFO - PID 11970 | 13:44:36 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.44921161825727 ms/frame 13:44:36 INFO - PID 11970 | 13:44:36 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.911309523809516 ms/frame 13:44:36 INFO - PID 11970 | 13:44:36 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.496992337164738 ms/frame 13:44:36 INFO - PID 11970 | 13:44:36 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.875108695652196 ms/frame 13:44:36 INFO - PID 11970 | 13:44:36 INFO - PID 11970 | Cycle 1(8): loaded http://localhost:42803/tests/video/video_playback.html (next: http://localhost:42803/tests/video/video_playback.html) 13:45:22 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6838243546576879 ms/frame 13:45:22 INFO - PID 11970 | 13:45:22 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6659825145711904 ms/frame 13:45:22 INFO - PID 11970 | 13:45:22 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7414712710388853 ms/frame 13:45:22 INFO - PID 11970 | 13:45:22 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7567295873573319 ms/frame 13:45:22 INFO - PID 11970 | 13:45:22 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_2_startup = 4.076603260869564 ms/frame 13:45:22 INFO - PID 11970 | 13:45:22 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.968660714285714 ms/frame 13:45:22 INFO - PID 11970 | 13:45:22 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1_startup = 3.4374799541809833 ms/frame 13:45:22 INFO - PID 11970 | 13:45:22 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3333750000000024 ms/frame 13:45:22 INFO - PID 11970 | 13:45:22 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.619466292134828 ms/frame 13:45:22 INFO - PID 11970 | 13:45:22 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.420745257452578 ms/frame 13:45:22 INFO - PID 11970 | 13:45:22 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_2_startup = 10.035066889632109 ms/frame 13:45:22 INFO - PID 11970 | 13:45:22 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_2_inclip = 10.258230769230767 ms/frame 13:45:22 INFO - PID 11970 | 13:45:22 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.153568773234191 ms/frame 13:45:22 INFO - PID 11970 | 13:45:22 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.869538043478276 ms/frame 13:45:22 INFO - PID 11970 | 13:45:22 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.502187500000007 ms/frame 13:45:22 INFO - PID 11970 | 13:45:22 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.051144578313284 ms/frame 13:45:22 INFO - PID 11970 | 13:45:22 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.629631782945735 ms/frame 13:45:22 INFO - PID 11970 | 13:45:22 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.2369943820225 ms/frame 13:45:22 INFO - PID 11970 | 13:45:22 INFO - PID 11970 | Cycle 1(9): loaded http://localhost:42803/tests/video/video_playback.html (next: http://localhost:42803/tests/video/video_playback.html) 13:46:08 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6828266965787997 ms/frame 13:46:08 INFO - PID 11970 | 13:46:08 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6656869275603665 ms/frame 13:46:08 INFO - PID 11970 | 13:46:08 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7607482394366194 ms/frame 13:46:08 INFO - PID 11970 | 13:46:08 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7029276595744678 ms/frame 13:46:08 INFO - PID 11970 | 13:46:08 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_2_startup = 4.054162162162162 ms/frame 13:46:08 INFO - PID 11970 | 13:46:08 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.915117416829746 ms/frame 13:46:08 INFO - PID 11970 | 13:46:08 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1_startup = 3.436981672394042 ms/frame 13:46:08 INFO - PID 11970 | 13:46:08 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3728246205733603 ms/frame 13:46:08 INFO - PID 11970 | 13:46:08 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.72568702290076 ms/frame 13:46:08 INFO - PID 11970 | 13:46:08 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.349558823529414 ms/frame 13:46:08 INFO - PID 11970 | 13:46:08 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_2_startup = 10.00123333333333 ms/frame 13:46:08 INFO - PID 11970 | 13:46:08 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_2_inclip = 9.853719211822662 ms/frame 13:46:08 INFO - PID 11970 | 13:46:08 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.112018518518502 ms/frame 13:46:08 INFO - PID 11970 | 13:46:08 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.812378378378384 ms/frame 13:46:08 INFO - PID 11970 | 13:46:08 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.508541666666678 ms/frame 13:46:08 INFO - PID 11970 | 13:46:08 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.978473053892209 ms/frame 13:46:08 INFO - PID 11970 | 13:46:08 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.409049429657774 ms/frame 13:46:08 INFO - PID 11970 | 13:46:08 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.815567567567593 ms/frame 13:46:08 INFO - PID 11970 | 13:46:08 INFO - PID 11970 | Cycle 1(10): loaded http://localhost:42803/tests/video/video_playback.html (next: http://localhost:42803/tests/video/video_playback.html) 13:46:55 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1_startup = 1.693411399548533 ms/frame 13:46:55 INFO - PID 11970 | 13:46:55 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6702963272120204 ms/frame 13:46:55 INFO - PID 11970 | 13:46:55 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7493352769679305 ms/frame 13:46:55 INFO - PID 11970 | 13:46:55 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7064505119453925 ms/frame 13:46:55 INFO - PID 11970 | 13:46:55 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_2_startup = 4.00628170894526 ms/frame 13:46:55 INFO - PID 11970 | 13:46:55 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.945424063116371 ms/frame 13:46:55 INFO - PID 11970 | 13:46:55 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1_startup = 3.397502831257077 ms/frame 13:46:55 INFO - PID 11970 | 13:46:55 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1_inclip = 3.345685618729099 ms/frame 13:46:55 INFO - PID 11970 | 13:46:55 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.640347744360904 ms/frame 13:46:55 INFO - PID 11970 | 13:46:55 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.542520775623265 ms/frame 13:46:55 INFO - PID 11970 | 13:46:55 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_2_startup = 10.204659863945585 ms/frame 13:46:55 INFO - PID 11970 | 13:46:55 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_2_inclip = 10.005299999999988 ms/frame 13:46:55 INFO - PID 11970 | 13:46:55 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.407718631178719 ms/frame 13:46:55 INFO - PID 11970 | 13:46:55 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.754032258064516 ms/frame 13:46:55 INFO - PID 11970 | 13:46:55 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.348395061728409 ms/frame 13:46:55 INFO - PID 11970 | 13:46:55 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.766852941176458 ms/frame 13:46:55 INFO - PID 11970 | 13:46:55 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.49480842911879 ms/frame 13:46:55 INFO - PID 11970 | 13:46:55 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.75612903225806 ms/frame 13:46:55 INFO - PID 11970 | 13:46:55 INFO - PID 11970 | Cycle 1(11): loaded http://localhost:42803/tests/video/video_playback.html (next: http://localhost:42803/tests/video/video_playback.html) 13:47:41 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1_startup = 1.679381645215445 ms/frame 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6683361134278565 ms/frame 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7332900057770073 ms/frame 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7184621993127156 ms/frame 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_2_startup = 4.054749999999999 ms/frame 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.033850806451615 ms/frame 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1_startup = 3.6158132530120484 ms/frame 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1_inclip = 3.5028633975481585 ms/frame 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.587886405959031 ms/frame 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.5580000000000025 ms/frame 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_2_startup = 10.13706081081081 ms/frame 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | testsrc.480p.60fps.webm_scale_2_inclip = 10.156167512690352 ms/frame 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.114981481481475 ms/frame 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.528447368421046 ms/frame 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.297131147540984 ms/frame 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.699356725146178 ms/frame 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.583436293436296 ms/frame 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.934644808743174 ms/frame 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | Cycle 1(12): loaded http://localhost:42803/tests/video/video_playback.html (next: http://localhost:42803/tests/video/video_playback.html) 13:47:41 INFO - PID 11970 | __start_tp_report 13:47:41 INFO - PID 11970 | _x_x_mozilla_page_load 13:47:41 INFO - PID 11970 | _x_x_mozilla_page_load_details 13:47:41 INFO - PID 11970 | |i|pagename|runs| 13:47:41 INFO - PID 11970 | |0;240p.120fps.mp4_scale_1_startup;1.677873113471213;1.6779026845637586;1.6799440089585667;1.683773849607183;1.6915727170236752;1.6803079507278837;1.677096143096702;1.6810616246498598;1.6838243546576879;1.6828266965787997;1.693411399548533;1.679381645215445 13:47:41 INFO - PID 11970 | |1;240p.120fps.mp4_scale_1_inclip;1.6697662771285473;1.6674916666666668;1.668277731442869;1.6660491257285597;1.667383333333333;1.6711528822055142;1.668240200166806;1.6669000000000003;1.6659825145711904;1.6656869275603665;1.6702963272120204;1.6683361134278565 13:47:41 INFO - PID 11970 | |2;240p.120fps.mp4_scale_1.1_startup;1.750717619603267;1.7236444572085008;1.7629259694477086;1.74768782760629;1.7334546504910455;1.7794928825622778;1.7397101449275363;1.722726750861079;1.7414712710388853;1.7607482394366194;1.7493352769679305;1.7332900057770073 13:47:41 INFO - PID 11970 | |3;240p.120fps.mp4_scale_1.1_inclip;1.7142502142245077;1.7013180272108852;1.7131806506849314;1.7168240343347643;1.7170729613733908;1.7303892733564021;1.732268398268398;1.6896706081081085;1.7567295873573319;1.7029276595744678;1.7064505119453925;1.7184621993127156 13:47:41 INFO - PID 11970 | |4;240p.120fps.mp4_scale_2_startup;3.9855976095617516;3.9435282522996076;4.033393817204303;4.099713114754098;4.138151724137931;4.133181818181819;4.076216032608698;3.979316976127322;4.076603260869564;4.054162162162162;4.00628170894526;4.054749999999999 13:47:41 INFO - PID 11970 | |5;240p.120fps.mp4_scale_2_inclip;4.073625254582484;4.098913934426227;3.5660160427807486;4.193846960167715;4.149657676348548;4.033407258064516;3.9451972386587775;4.167916666666664;3.968660714285714;3.915117416829746;3.945424063116371;4.033850806451615 13:47:41 INFO - PID 11970 | |6;480p.60fps.webm_scale_1_startup;3.4487298850574697;3.5171101992965994;3.437657502863689;3.5473995271867618;3.5551658767772505;3.4170842824601375;3.41433447098976;3.421271379703535;3.4374799541809833;3.436981672394042;3.397502831257077;3.6158132530120484 13:47:41 INFO - PID 11970 | |7;480p.60fps.webm_scale_1_inclip;3.344590301003348;3.436434707903782;3.3565520134228146;3.4258561643835628;3.5030035026269704;3.3453344481605325;3.356375838926177;3.3576174496644287;3.3333750000000024;3.3728246205733603;3.345685618729099;3.5028633975481585 13:47:41 INFO - PID 11970 | |8;480p.60fps.webm_scale_1.1_startup;5.30223498233216;5.703868821292777;5.537167896678961;5.597388059701494;5.7049524714828905;5.587001862197395;5.629906191369609;5.650263653483988;5.619466292134828;5.72568702290076;5.640347744360904;5.587886405959031 13:47:41 INFO - PID 11970 | |9;480p.60fps.webm_scale_1.1_inclip;5.589273743016757;5.169315245478031;5.556875000000006;5.52653314917127;5.571782729805015;5.449822888283377;5.479712328767117;5.668654390934854;5.420745257452578;5.349558823529414;5.542520775623265;5.5580000000000025 13:47:41 INFO - PID 11970 | |10;480p.60fps.webm_scale_2_startup;10.566373239436615;10.41819444444444;10.718035714285712;10.49115384615385;10.20749999999999;10.680391459074741;10.312766323024054;10.565669014084513;10.035066889632109;10.00123333333333;10.204659863945585;10.13706081081081 13:47:41 INFO - PID 11970 | |11;480p.60fps.webm_scale_2_inclip;9.854950738916257;10.000575000000008;10.10209595959596;10.003575000000001;10.003075000000008;10.256641025641017;9.904034653465354;9.758121951219517;10.258230769230767;9.853719211822662;10.005299999999988;10.156167512690352 13:47:41 INFO - PID 11970 | |12;1080p.60fps.mp4_scale_1_startup;11.11433333333333;10.99003663003664;11.198917910447767;10.951350364963497;11.112925925925918;11.155390334572488;10.873242753623199;11.32466037735849;11.153568773234191;11.112018518518502;11.407718631178719;11.114981481481475 13:47:41 INFO - PID 11970 | |13;1080p.60fps.mp4_scale_1_inclip;10.755860215053744;10.47371727748689;10.53160526315788;10.695802139037422;10.697005347593603;10.585555555555585;10.585608465608468;10.696256684492003;10.869538043478276;10.812378378378384;10.754032258064516;10.528447368421046 13:47:41 INFO - PID 11970 | |14;1080p.60fps.mp4_scale_1.1_startup;12.609621848739511;12.661518987341767;12.501416666666682;12.605273109243699;12.146275303643744;12.771446808510643;12.450082987551871;12.44921161825727;12.502187500000007;12.508541666666678;12.348395061728409;12.297131147540984 13:47:41 INFO - PID 11970 | |15;1080p.60fps.mp4_scale_1.1_inclip;11.978473053892209;11.904374999999986;11.697426900584764;11.907261904761938;11.904642857142832;11.976826347305417;11.839112426035532;11.911309523809516;12.051144578313284;11.978473053892209;11.766852941176458;11.699356725146178 13:47:41 INFO - PID 11970 | |16;1080p.60fps.mp4_scale_2_startup;11.40910646387833;11.495919540229876;11.630329457364342;11.583648648648651;11.587065637065649;11.540442307692306;11.58332046332047;11.496992337164738;11.629631782945735;11.409049429657774;11.49480842911879;11.583436293436296 13:47:41 INFO - PID 11970 | |17;1080p.60fps.mp4_scale_2_inclip;11.054033149171264;11.050690607734822;11.175418994413416;11.053287292817702;10.930928961748638;10.990851648351644;11.051381215469629;10.875108695652196;11.2369943820225;10.815567567567593;10.75612903225806;10.934644808743174 13:47:41 INFO - PID 11970 | __end_tp_report 13:47:41 INFO - PID 11970 | __start_cc_report 13:47:41 INFO - PID 11970 | _x_x_mozilla_cycle_collect,555 13:47:41 INFO - PID 11970 | __end_cc_report 13:47:41 INFO - PID 11970 | __startTimestamp1510264061510__endTimestamp 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | ------- Summary: start ------- 13:47:41 INFO - PID 11970 | Number of tests: 18 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | [#0] 240p.120fps.mp4_scale_1_startup Cycles:12 Average:1.68 Median:1.68 stddev:0.01 (0.3%) stddev-sans-first:0.01 13:47:41 INFO - PID 11970 | 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:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | [#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:47:41 INFO - PID 11970 | 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:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | [#2] 240p.120fps.mp4_scale_1.1_startup Cycles:12 Average:1.75 Median:1.75 stddev:0.02 (1.0%) stddev-sans-first:0.02 13:47:41 INFO - PID 11970 | Values: 1.8 1.7 1.8 1.7 1.7 1.8 1.7 1.7 1.7 1.8 1.7 1.7 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | [#3] 240p.120fps.mp4_scale_1.1_inclip Cycles:12 Average:1.72 Median:1.72 stddev:0.02 (1.0%) stddev-sans-first:0.02 13:47:41 INFO - PID 11970 | Values: 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.8 1.7 1.7 1.7 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | [#4] 240p.120fps.mp4_scale_2_startup Cycles:12 Average:4.05 Median:4.07 stddev:0.06 (1.5%) stddev-sans-first:0.06 13:47:41 INFO - PID 11970 | Values: 4.0 3.9 4.0 4.1 4.1 4.1 4.1 4.0 4.1 4.1 4.0 4.1 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | [#5] 240p.120fps.mp4_scale_2_inclip Cycles:12 Average:4.01 Median:4.05 stddev:0.17 (4.1%) stddev-sans-first:0.17 13:47:41 INFO - PID 11970 | Values: 4.1 4.1 3.6 4.2 4.1 4.0 3.9 4.2 4.0 3.9 3.9 4.0 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | [#6] 480p.60fps.webm_scale_1_startup Cycles:12 Average:3.47 Median:3.44 stddev:0.07 (2.0%) stddev-sans-first:0.07 13:47:41 INFO - PID 11970 | Values: 3.4 3.5 3.4 3.5 3.6 3.4 3.4 3.4 3.4 3.4 3.4 3.6 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | [#7] 480p.60fps.webm_scale_1_inclip Cycles:12 Average:3.39 Median:3.37 stddev:0.06 (1.8%) stddev-sans-first:0.06 13:47:41 INFO - PID 11970 | Values: 3.3 3.4 3.4 3.4 3.5 3.3 3.4 3.4 3.3 3.4 3.3 3.5 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | [#8] 480p.60fps.webm_scale_1.1_startup Cycles:12 Average:5.61 Median:5.64 stddev:0.11 (2.0%) stddev-sans-first:0.06 13:47:41 INFO - PID 11970 | Values: 5.3 5.7 5.5 5.6 5.7 5.6 5.6 5.7 5.6 5.7 5.6 5.6 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | [#9] 480p.60fps.webm_scale_1.1_inclip Cycles:12 Average:5.49 Median:5.55 stddev:0.13 (2.4%) stddev-sans-first:0.13 13:47:41 INFO - PID 11970 | Values: 5.6 5.2 5.6 5.5 5.6 5.4 5.5 5.7 5.4 5.3 5.5 5.6 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | [#10] 480p.60fps.webm_scale_2_startup Cycles:12 Average:10.36 Median:10.45 stddev:0.25 (2.4%) stddev-sans-first:0.25 13:47:41 INFO - PID 11970 | Values: 10.6 10.4 10.7 10.5 10.2 10.7 10.3 10.6 10.0 10.0 10.2 10.1 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | [#11] 480p.60fps.webm_scale_2_inclip Cycles:12 Average:10.01 Median:10.26 stddev:0.16 (1.5%) stddev-sans-first:0.16 13:47:41 INFO - PID 11970 | Values: 9.9 10.0 10.1 10.0 10.0 10.3 9.9 9.8 10.3 9.9 10.0 10.2 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | [#12] 1080p.60fps.mp4_scale_1_startup Cycles:12 Average:11.13 Median:11.13 stddev:0.15 (1.3%) stddev-sans-first:0.15 13:47:41 INFO - PID 11970 | Values: 11.1 11.0 11.2 11.0 11.1 11.2 10.9 11.3 11.2 11.1 11.4 11.1 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | [#13] 1080p.60fps.mp4_scale_1_inclip Cycles:12 Average:10.67 Median:10.70 stddev:0.12 (1.2%) stddev-sans-first:0.13 13:47:41 INFO - PID 11970 | Values: 10.8 10.5 10.5 10.7 10.7 10.6 10.6 10.7 10.9 10.8 10.8 10.5 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | [#14] 1080p.60fps.mp4_scale_1.1_startup Cycles:12 Average:12.49 Median:12.51 stddev:0.17 (1.4%) stddev-sans-first:0.17 13:47:41 INFO - PID 11970 | Values: 12.6 12.7 12.5 12.6 12.1 12.8 12.5 12.4 12.5 12.5 12.3 12.3 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | [#15] 1080p.60fps.mp4_scale_1.1_inclip Cycles:12 Average:11.88 Median:11.91 stddev:0.11 (1.0%) stddev-sans-first:0.11 13:47:41 INFO - PID 11970 | Values: 12.0 11.9 11.7 11.9 11.9 12.0 11.8 11.9 12.1 12.0 11.8 11.7 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | [#16] 1080p.60fps.mp4_scale_2_startup Cycles:12 Average:11.54 Median:11.58 stddev:0.08 (0.7%) stddev-sans-first:0.07 13:47:41 INFO - PID 11970 | Values: 11.4 11.5 11.6 11.6 11.6 11.5 11.6 11.5 11.6 11.4 11.5 11.6 13:47:41 INFO - PID 11970 | 13:47:41 INFO - PID 11970 | [#17] 1080p.60fps.mp4_scale_2_inclip Cycles:12 Average:10.99 Median:11.05 stddev:0.14 (1.3%) stddev-sans-first:0.15 13:47:41 INFO - PID 11970 | Values: 11.1 11.1 11.2 11.1 10.9 11.0 11.1 10.9 11.2 10.8 10.8 10.9 13:47:41 INFO - PID 11970 | -------- Summary: end -------- 13:47:41 INFO - PID 11970 | 13:47:42 INFO - TEST-INFO | 11970: exit 0 13:47:42 INFO - TEST-OK | basic_compositor_video | took 561590ms 13:47:42 INFO - TEST-START | glvideo 13:47:42 INFO - Initialising browser for glvideo test... 13:47:42 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:42803/getInfo.html -profile /tmp/tmp9iUMZw/profile 13:47:42 INFO - TEST-INFO | started process 13208 (/builds/slave/test/build/application/firefox/firefox http://localhost:42803/getInfo.html) 13:47:47 INFO - TEST-INFO | 13208: exit 0 13:47:47 INFO - Browser initialized. 13:47:47 INFO - Running cycle 1/1 for glvideo test... 13:47:47 INFO - Using env: {'DISPLAY': ':0', 13:47:47 INFO - 'HOME': '/home/cltbld', 13:47:47 INFO - 'JSGC_DISABLE_POISONING': '1', 13:47:47 INFO - 'LANG': 'en_US.UTF-8', 13:47:47 INFO - 'LANGUAGE': 'en_US:en', 13:47:47 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 13:47:47 INFO - 'LOGNAME': 'cltbld', 13:47:47 INFO - 'MAIL': '/var/mail/cltbld', 13:47:47 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 13:47:47 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 13:47:47 INFO - 'MOZ_CRASHREPORTER': '1', 13:47:47 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:47:47 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 13:47:47 INFO - 'MOZ_NO_REMOTE': '1', 13:47:47 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 13:47:47 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:47:47 INFO - 'NO_EM_RESTART': '1', 13:47:47 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:47:47 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:47:47 INFO - 'PWD': '/builds/slave/test', 13:47:47 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 13:47:47 INFO - 'RUST_BACKTRACE': 'full', 13:47:47 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 13:47:47 INFO - 'SHELL': '/bin/bash', 13:47:47 INFO - 'SHLVL': '1', 13:47:47 INFO - 'STYLO_FORCE_DISABLED': '1', 13:47:47 INFO - 'TERM': 'linux', 13:47:47 INFO - 'TMOUT': '86400', 13:47:47 INFO - 'USER': 'cltbld', 13:47:47 INFO - 'XDG_SESSION_COOKIE': '745a4373a2a16df560f216e000000264-1510263420.469241-1453849038', 13:47:47 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:47:47 INFO - '_': '/tools/buildbot/bin/python'} 13:47:47 INFO - TEST-INFO | started process 13480 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp9iUMZw/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/webgl/glvideo.manifest.develop -tpnoisy -tploadnocache -tpcycles 1 -tppagecycles 5) 13:47:48 INFO - PID 13480 | 13:47:48 INFO - PID 13480 | (/builds/slave/test/build/application/firefox/firefox:13534): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 13:47:48 INFO - PID 13480 | 13:47:50 INFO - PID 13480 | [talos glvideo result] Mean tick time across 100 ticks: 8.550799999999999 ms 13:47:50 INFO - PID 13480 | Cycle 1(1): loaded http://localhost:42803/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:42803/tests/webgl/benchmarks/video/video_upload.html) 13:47:51 INFO - PID 13480 | [talos glvideo result] Mean tick time across 100 ticks: 6.59155 ms 13:47:51 INFO - PID 13480 | Cycle 1(2): loaded http://localhost:42803/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:42803/tests/webgl/benchmarks/video/video_upload.html) 13:47:52 INFO - PID 13480 | [talos glvideo result] Mean tick time across 100 ticks: 6.59535 ms 13:47:52 INFO - PID 13480 | Cycle 1(3): loaded http://localhost:42803/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:42803/tests/webgl/benchmarks/video/video_upload.html) 13:47:54 INFO - PID 13480 | [talos glvideo result] Mean tick time across 100 ticks: 6.58835 ms 13:47:54 INFO - PID 13480 | Cycle 1(4): loaded http://localhost:42803/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:42803/tests/webgl/benchmarks/video/video_upload.html) 13:47:55 INFO - PID 13480 | [talos glvideo result] Mean tick time across 100 ticks: 6.684450000000001 ms 13:47:55 INFO - PID 13480 | Cycle 1(5): loaded http://localhost:42803/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:42803/tests/webgl/benchmarks/video/video_upload.html) 13:47:55 INFO - PID 13480 | __start_tp_report 13:47:55 INFO - PID 13480 | _x_x_mozilla_page_load 13:47:55 INFO - PID 13480 | _x_x_mozilla_page_load_details 13:47:55 INFO - PID 13480 | |i|pagename|runs| 13:47:55 INFO - PID 13480 | |0;Mean tick time across 100 ticks: ;8.550799999999999;6.59155;6.59535;6.58835;6.684450000000001 13:47:55 INFO - PID 13480 | __end_tp_report 13:47:55 INFO - PID 13480 | __start_cc_report 13:47:55 INFO - PID 13480 | _x_x_mozilla_cycle_collect,261 13:47:55 INFO - PID 13480 | __end_cc_report 13:47:55 INFO - PID 13480 | __startTimestamp1510264075601__endTimestamp 13:47:55 INFO - PID 13480 | 13:47:55 INFO - PID 13480 | ------- Summary: start ------- 13:47:55 INFO - PID 13480 | Number of tests: 1 13:47:55 INFO - PID 13480 | 13:47:55 INFO - PID 13480 | [#0] Mean tick time across 100 ticks: Cycles:5 Average:7.00 Median:6.60 stddev:0.87 (13.1%) stddev-sans-first:0.05 13:47:55 INFO - PID 13480 | Values: 8.6 6.6 6.6 6.6 6.7 13:47:55 INFO - PID 13480 | -------- Summary: end -------- 13:47:55 INFO - PID 13480 | 13:47:55 INFO - PID 13480 | *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping 13:47:56 INFO - TEST-INFO | 13480: exit 0 13:47:56 INFO - TEST-OK | glvideo | took 14118ms 13:47:56 INFO - SUITE-END | took 575s 13:47:56 INFO - Completed test suite (00:09:36) 13:47:56 INFO - PERFHERDER_DATA: {"framework": {"name": "talos"}, "suites": [{"extraOptions": ["e10s", "stylo_disabled"], "name": "basic_compositor_video", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 5.5739021805233255, "subtests": [{"name": "240p.120fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.677873113471213, 1.6779026845637586, 1.6799440089585667, 1.683773849607183, 1.6915727170236752, 1.6803079507278837, 1.677096143096702, 1.6810616246498598, 1.6838243546576879, 1.6828266965787997, 1.693411399548533, 1.679381645215445], "value": 1.6810616246498598, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.6697662771285473, 1.6674916666666668, 1.668277731442869, 1.6660491257285597, 1.667383333333333, 1.6711528822055142, 1.668240200166806, 1.6669000000000003, 1.6659825145711904, 1.6656869275603665, 1.6702963272120204, 1.6683361134278565], "value": 1.6674916666666668, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.750717619603267, 1.7236444572085008, 1.7629259694477086, 1.74768782760629, 1.7334546504910455, 1.7794928825622778, 1.7397101449275363, 1.722726750861079, 1.7414712710388853, 1.7607482394366194, 1.7493352769679305, 1.7332900057770073], "value": 1.7414712710388853, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.7142502142245077, 1.7013180272108852, 1.7131806506849314, 1.7168240343347643, 1.7170729613733908, 1.7303892733564021, 1.732268398268398, 1.6896706081081085, 1.7567295873573319, 1.7029276595744678, 1.7064505119453925, 1.7184621993127156], "value": 1.7168240343347643, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.9855976095617516, 3.9435282522996076, 4.033393817204303, 4.099713114754098, 4.138151724137931, 4.133181818181819, 4.076216032608698, 3.979316976127322, 4.076603260869564, 4.054162162162162, 4.00628170894526, 4.054749999999999], "value": 4.054749999999999, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.073625254582484, 4.098913934426227, 3.5660160427807486, 4.193846960167715, 4.149657676348548, 4.033407258064516, 3.9451972386587775, 4.167916666666664, 3.968660714285714, 3.915117416829746, 3.945424063116371, 4.033850806451615], "value": 4.033407258064516, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.4487298850574697, 3.5171101992965994, 3.437657502863689, 3.5473995271867618, 3.5551658767772505, 3.4170842824601375, 3.41433447098976, 3.421271379703535, 3.4374799541809833, 3.436981672394042, 3.397502831257077, 3.6158132530120484], "value": 3.4374799541809833, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.344590301003348, 3.436434707903782, 3.3565520134228146, 3.4258561643835628, 3.5030035026269704, 3.3453344481605325, 3.356375838926177, 3.3576174496644287, 3.3333750000000024, 3.3728246205733603, 3.345685618729099, 3.5028633975481585], "value": 3.3576174496644287, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.30223498233216, 5.703868821292777, 5.537167896678961, 5.597388059701494, 5.7049524714828905, 5.587001862197395, 5.629906191369609, 5.650263653483988, 5.619466292134828, 5.72568702290076, 5.640347744360904, 5.587886405959031], "value": 5.629906191369609, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.589273743016757, 5.169315245478031, 5.556875000000006, 5.52653314917127, 5.571782729805015, 5.449822888283377, 5.479712328767117, 5.668654390934854, 5.420745257452578, 5.349558823529414, 5.542520775623265, 5.5580000000000025], "value": 5.52653314917127, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.566373239436615, 10.41819444444444, 10.718035714285712, 10.49115384615385, 10.20749999999999, 10.680391459074741, 10.312766323024054, 10.565669014084513, 10.035066889632109, 10.00123333333333, 10.204659863945585, 10.13706081081081], "value": 10.312766323024054, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [9.854950738916257, 10.000575000000008, 10.10209595959596, 10.003575000000001, 10.003075000000008, 10.256641025641017, 9.904034653465354, 9.758121951219517, 10.258230769230767, 9.853719211822662, 10.005299999999988, 10.156167512690352], "value": 10.003575000000001, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.11433333333333, 10.99003663003664, 11.198917910447767, 10.951350364963497, 11.112925925925918, 11.155390334572488, 10.873242753623199, 11.32466037735849, 11.153568773234191, 11.112018518518502, 11.407718631178719, 11.114981481481475], "value": 11.114981481481475, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.755860215053744, 10.47371727748689, 10.53160526315788, 10.695802139037422, 10.697005347593603, 10.585555555555585, 10.585608465608468, 10.696256684492003, 10.869538043478276, 10.812378378378384, 10.754032258064516, 10.528447368421046], "value": 10.695802139037422, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [12.609621848739511, 12.661518987341767, 12.501416666666682, 12.605273109243699, 12.146275303643744, 12.771446808510643, 12.450082987551871, 12.44921161825727, 12.502187500000007, 12.508541666666678, 12.348395061728409, 12.297131147540984], "value": 12.501416666666682, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.978473053892209, 11.904374999999986, 11.697426900584764, 11.907261904761938, 11.904642857142832, 11.976826347305417, 11.839112426035532, 11.911309523809516, 12.051144578313284, 11.978473053892209, 11.766852941176458, 11.699356725146178], "value": 11.904642857142832, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.40910646387833, 11.495919540229876, 11.630329457364342, 11.583648648648651, 11.587065637065649, 11.540442307692306, 11.58332046332047, 11.496992337164738, 11.629631782945735, 11.409049429657774, 11.49480842911879, 11.583436293436296], "value": 11.58332046332047, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.054033149171264, 11.050690607734822, 11.175418994413416, 11.053287292817702, 10.930928961748638, 10.990851648351644, 11.051381215469629, 10.875108695652196, 11.2369943820225, 10.815567567567593, 10.75612903225806, 10.934644808743174], "value": 10.990851648351644, "unit": "ms/frame"}]}, {"lowerIsBetter": true, "subtests": [{"name": "Mean tick time across 100 ticks: ", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [8.550799999999999, 6.59155, 6.59535, 6.58835, 6.684450000000001], "value": 6.59345, "unit": "ms"}], "extraOptions": ["e10s", "stylo_disabled"], "name": "glvideo", "alertThreshold": 2.0}]} 13:47:56 INFO - Return code: 0 13:47:56 INFO - Validating PERFHERDER_DATA against /builds/slave/test/scripts/external_tools/performance-artifact-schema.json 13:47:56 INFO - # TBPL SUCCESS # 13:47:56 INFO - Running post-action listener: _package_coverage_data 13:47:56 INFO - Running post-action listener: _resource_record_post_action 13:47:56 INFO - [mozharness: 2017-11-09 21:47:56.793777Z] Finished run-tests step (success) 13:47:56 INFO - Running post-run listener: _resource_record_post_run 13:47:56 INFO - Total resource usage - Wall time: 595s; CPU: 38.0%; Read bytes: 8904704; Write bytes: 310398976; Read time: 672; Write time: 385360 13:47:56 INFO - TinderboxPrint: CPU usage
38.4% 13:47:56 INFO - TinderboxPrint: I/O read bytes / time
8,904,704 / 672 13:47:56 INFO - TinderboxPrint: I/O write bytes / time
310,398,976 / 385,360 13:47:56 INFO - TinderboxPrint: CPU idle
2,874.4 (61.6%) 13:47:56 INFO - TinderboxPrint: CPU system
302.2 (6.5%) 13:47:56 INFO - TinderboxPrint: CPU user
1,474.2 (31.6%) 13:47:56 INFO - TinderboxPrint: Swap in / out
0 / 0 13:47:56 INFO - install - Wall time: 19s; CPU: 13.0%; Read bytes: 0; Write bytes: 6279168; Read time: 0; Write time: 1088 13:47:56 INFO - setup-mitmproxy - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0 13:47:56 INFO - run-tests - Wall time: 577s; CPU: 39.0%; Read bytes: 8904704; Write bytes: 303640576; Read time: 672; Write time: 384224 13:47:57 INFO - Running post-run listener: _upload_blobber_files 13:47:57 INFO - Blob upload gear active. 13:47:57 INFO - Preparing to upload files from /builds/slave/test/build/blobber_upload_dir. 13:47:57 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:47:57 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:47:57 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:47:57 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:47:57 INFO - SNIMissingWarning 13:47:57 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:47:57 INFO - InsecurePlatformWarning 13:47:57 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:47:57 INFO - SubjectAltNameWarning 13:47:57 INFO - (blobuploader) - INFO - Open directory for files ... 13:47:57 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/perfherder-data.json ... 13:47:57 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 13:47:57 INFO - (blobuploader) - INFO - Uploading, attempt #1. 13:47:57 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:47:57 INFO - InsecurePlatformWarning 13:47:57 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:47:57 INFO - SubjectAltNameWarning 13:47:58 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:47:58 INFO - InsecurePlatformWarning 13:47:58 INFO - (blobuploader) - INFO - TinderboxPrint: perfherder-data.json: uploaded 13:47:58 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 13:47:58 INFO - (blobuploader) - INFO - Done attempting. 13:47:58 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/resource-usage.json ... 13:47:58 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 13:47:58 INFO - (blobuploader) - INFO - Uploading, attempt #1. 13:47:58 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:47:58 INFO - InsecurePlatformWarning 13:47:58 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:47:58 INFO - SubjectAltNameWarning 13:48:00 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:48:00 INFO - InsecurePlatformWarning 13:48:00 INFO - (blobuploader) - INFO - TinderboxPrint: resource-usage.json: uploaded 13:48:00 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 13:48:00 INFO - (blobuploader) - INFO - Done attempting. 13:48:00 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_raw.log ... 13:48:00 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 13:48:00 INFO - (blobuploader) - INFO - Uploading, attempt #1. 13:48:01 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:48:01 INFO - InsecurePlatformWarning 13:48:01 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:48:01 INFO - SubjectAltNameWarning 13:48:01 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:48:01 INFO - InsecurePlatformWarning 13:48:01 INFO - (blobuploader) - INFO - TinderboxPrint: g4-stylo-disabled-e10s_raw.log: uploaded 13:48:01 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 13:48:01 INFO - (blobuploader) - INFO - Done attempting. 13:48:01 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_errorsummary.log ... 13:48:01 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 13:48:01 INFO - (blobuploader) - INFO - Uploading, attempt #1. 13:48:01 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:48:01 INFO - InsecurePlatformWarning 13:48:02 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:48:02 INFO - SubjectAltNameWarning 13:48:02 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:48:02 INFO - InsecurePlatformWarning 13:48:02 INFO - (blobuploader) - INFO - TinderboxPrint: g4-stylo-disabled-e10s_errorsummary.log: uploaded 13:48:02 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 13:48:02 INFO - (blobuploader) - INFO - Done attempting. 13:48:02 INFO - (blobuploader) - INFO - Iteration through files over. 13:48:02 INFO - Return code: 0 13:48:02 INFO - rmtree: /builds/slave/test/build/uploaded_files.json 13:48:02 INFO - retry: Calling remove with args: ('/builds/slave/test/build/uploaded_files.json',), kwargs: {}, attempt #1 13:48:02 INFO - Setting buildbot property blobber_files to {"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/0e6bf349c1bb7a93a115105203a484a86d670ac68eba79b98bc2de872d5f6fb63631bacfcad4acdd6136489280a513786a186dd2ae8531cdc1c50c8dbced8018", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/1867405c19ac7f9266b07cb3424788a8924d3b37801c4bed72e06c36fcb41cce3b0b985a2fcd0eef9a66e13d2769672007a64be1f4b54433b2d4f7073d8c4c14", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/0e6f976a12810ec8c9c8e70121e0b6ca8f8ef791b3722fc66460d81b088dfd59ae864a03a26552255f9007ca88c32e13f20fb16672e0c7a18b3fa9cb73b934a7", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/f29cc8d8715c5a650e44bc2826dbe50cd1b9cb61778c94bac8b1b1b98c0ae1971191c10b6d03293d1abce85125ba5441f1c6a59af0adf1d7416d83d5743960fc"} 13:48:02 INFO - Writing buildbot properties ['blobber_files'] to /builds/slave/test/properties/blobber_files 13:48:02 INFO - Writing to file /builds/slave/test/properties/blobber_files 13:48:02 INFO - Contents: 13:48:02 INFO - blobber_files:{"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/0e6bf349c1bb7a93a115105203a484a86d670ac68eba79b98bc2de872d5f6fb63631bacfcad4acdd6136489280a513786a186dd2ae8531cdc1c50c8dbced8018", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/1867405c19ac7f9266b07cb3424788a8924d3b37801c4bed72e06c36fcb41cce3b0b985a2fcd0eef9a66e13d2769672007a64be1f4b54433b2d4f7073d8c4c14", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/0e6f976a12810ec8c9c8e70121e0b6ca8f8ef791b3722fc66460d81b088dfd59ae864a03a26552255f9007ca88c32e13f20fb16672e0c7a18b3fa9cb73b934a7", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/f29cc8d8715c5a650e44bc2826dbe50cd1b9cb61778c94bac8b1b1b98c0ae1971191c10b6d03293d1abce85125ba5441f1c6a59af0adf1d7416d83d5743960fc"} 13:48:02 INFO - Running post-run listener: copy_logs_to_upload_dir 13:48:02 INFO - Copying logs to upload dir... 13:48:02 INFO - mkdir: /builds/slave/test/build/upload/logs 13:48:02 INFO - Copying logs to upload dir... program finished with exit code 0 elapsedTime=659.063594 ========= master_lag: 0.05 ========= ========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 10 mins, 59 secs) (at 2017-11-09 13:48:02.801287) ========= ========= Started set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-11-09 13:48:02.804984) ========= 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=745a4373a2a16df560f216e000000264-1510263420.469241-1453849038 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/0e6bf349c1bb7a93a115105203a484a86d670ac68eba79b98bc2de872d5f6fb63631bacfcad4acdd6136489280a513786a186dd2ae8531cdc1c50c8dbced8018", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/1867405c19ac7f9266b07cb3424788a8924d3b37801c4bed72e06c36fcb41cce3b0b985a2fcd0eef9a66e13d2769672007a64be1f4b54433b2d4f7073d8c4c14", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/0e6f976a12810ec8c9c8e70121e0b6ca8f8ef791b3722fc66460d81b088dfd59ae864a03a26552255f9007ca88c32e13f20fb16672e0c7a18b3fa9cb73b934a7", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/f29cc8d8715c5a650e44bc2826dbe50cd1b9cb61778c94bac8b1b1b98c0ae1971191c10b6d03293d1abce85125ba5441f1c6a59af0adf1d7416d83d5743960fc"} build_url:https://queue.taskcluster.net/v1/task/TXEoGj7dQvmJaiobeEs1dw/artifacts/public/build/target.tar.bz2 program finished with exit code 0 elapsedTime=0.011611 build_url: 'https://queue.taskcluster.net/v1/task/TXEoGj7dQvmJaiobeEs1dw/artifacts/public/build/target.tar.bz2' blobber_files: '{"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/0e6bf349c1bb7a93a115105203a484a86d670ac68eba79b98bc2de872d5f6fb63631bacfcad4acdd6136489280a513786a186dd2ae8531cdc1c50c8dbced8018", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/1867405c19ac7f9266b07cb3424788a8924d3b37801c4bed72e06c36fcb41cce3b0b985a2fcd0eef9a66e13d2769672007a64be1f4b54433b2d4f7073d8c4c14", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/0e6f976a12810ec8c9c8e70121e0b6ca8f8ef791b3722fc66460d81b088dfd59ae864a03a26552255f9007ca88c32e13f20fb16672e0c7a18b3fa9cb73b934a7", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/f29cc8d8715c5a650e44bc2826dbe50cd1b9cb61778c94bac8b1b1b98c0ae1971191c10b6d03293d1abce85125ba5441f1c6a59af0adf1d7416d83d5743960fc"}' ========= master_lag: 0.02 ========= ========= Finished set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-11-09 13:48:02.837156) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-11-09 13:48:02.837687) ========= 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=745a4373a2a16df560f216e000000264-1510263420.469241-1453849038 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.004680 ========= master_lag: 0.08 ========= ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-11-09 13:48:02.921376) ========= ========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2017-11-09 13:48:02.921700) ========= ========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2017-11-09 13:48:02.922039) ========= ========= Total master_lag: 0.22 =========